0s autopkgtest [13:12:42]: starting date and time: 2024-06-03 13:12:42+0000 0s autopkgtest [13:12:42]: git checkout: 930f72e5 setup-testbed: don't install 'Recommends' for 'linux-generic' 0s autopkgtest [13:12:42]: host juju-7f2275-prod-proposed-migration-environment-3; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.v2mauylb/out --timeout-copy=6000 --setup-commands /home/ubuntu/autopkgtest-cloud/worker-config-production/setup-canonical.sh --apt-pocket=proposed=src:libxml2,src:libxml-libxml-perl --apt-upgrade asterisk --timeout-short=300 --timeout-copy=20000 --timeout-build=20000 '--env=ADT_TEST_TRIGGERS=libxml2/2.12.7+dfsg-3 libxml-libxml-perl/2.0207+dfsg+really+2.0134-3' -- ssh -s /home/ubuntu/autopkgtest/ssh-setup/nova -- --flavor autopkgtest --security-groups autopkgtest-juju-7f2275-prod-proposed-migration-environment-3@bos02-ppc64el-4.secgroup --name adt-oracular-ppc64el-asterisk-20240603-131242-juju-7f2275-prod-proposed-migration-environment-3-c62801ba-782e-4817-a0a3-36cb1b2cc2bb --image adt/ubuntu-oracular-ppc64el-server --keyname testbed-juju-7f2275-prod-proposed-migration-environment-3 --net-id=net_prod-proposed-migration -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'"'"'' --mirror=http://ftpmaster.internal/ubuntu/ 155s autopkgtest [13:15:17]: testbed dpkg architecture: ppc64el 155s autopkgtest [13:15:17]: testbed apt version: 2.9.3 155s autopkgtest [13:15:17]: @@@@@@@@@@@@@@@@@@@@ test bed setup 157s Get:1 http://ftpmaster.internal/ubuntu oracular-proposed InRelease [110 kB] 157s Get:2 http://ftpmaster.internal/ubuntu oracular-proposed/universe Sources [384 kB] 157s Get:3 http://ftpmaster.internal/ubuntu oracular-proposed/main Sources [43.4 kB] 157s Get:4 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse Sources [1680 B] 157s Get:5 http://ftpmaster.internal/ubuntu oracular-proposed/restricted Sources [4792 B] 157s Get:6 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el Packages [69.7 kB] 157s Get:7 http://ftpmaster.internal/ubuntu oracular-proposed/universe ppc64el Packages [348 kB] 157s Get:8 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse ppc64el Packages [1392 B] 157s Fetched 964 kB in 1s (1208 kB/s) 157s Reading package lists... 162s Reading package lists... 162s Building dependency tree... 162s Reading state information... 163s Calculating upgrade... 163s The following packages will be upgraded: 163s libxml2 163s 1 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 163s Need to get 728 kB of archives. 163s After this operation, 516 kB disk space will be freed. 163s Get:1 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el libxml2 ppc64el 2.12.7+dfsg-3 [728 kB] 164s Fetched 728 kB in 1s (1407 kB/s) 164s (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 ... 72596 files and directories currently installed.) 164s Preparing to unpack .../libxml2_2.12.7+dfsg-3_ppc64el.deb ... 164s Unpacking libxml2:ppc64el (2.12.7+dfsg-3) over (2.9.14+dfsg-1.3ubuntu3) ... 164s Setting up libxml2:ppc64el (2.12.7+dfsg-3) ... 164s Processing triggers for libc-bin (2.39-0ubuntu8.1) ... 164s Reading package lists... 164s Building dependency tree... 164s Reading state information... 164s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 165s Hit:1 http://ftpmaster.internal/ubuntu oracular-proposed InRelease 165s Hit:2 http://ftpmaster.internal/ubuntu oracular InRelease 165s Hit:3 http://ftpmaster.internal/ubuntu oracular-updates InRelease 165s Hit:4 http://ftpmaster.internal/ubuntu oracular-security InRelease 166s Reading package lists... 166s Reading package lists... 166s Building dependency tree... 166s Reading state information... 166s Calculating upgrade... 166s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 166s Reading package lists... 167s Building dependency tree... 167s Reading state information... 167s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 178s autopkgtest [13:15:40]: testbed running kernel: Linux 6.8.0-31-generic #31-Ubuntu SMP Sat Apr 20 00:05:55 UTC 2024 178s autopkgtest [13:15:40]: @@@@@@@@@@@@@@@@@@@@ apt-source asterisk 188s Get:1 http://ftpmaster.internal/ubuntu oracular/universe asterisk 1:20.6.0~dfsg+~cs6.13.40431414-2build5 (dsc) [5436 B] 188s Get:2 http://ftpmaster.internal/ubuntu oracular/universe asterisk 1:20.6.0~dfsg+~cs6.13.40431414-2build5 (tar) [11.3 kB] 188s Get:3 http://ftpmaster.internal/ubuntu oracular/universe asterisk 1:20.6.0~dfsg+~cs6.13.40431414-2build5 (tar) [21.9 kB] 188s Get:4 http://ftpmaster.internal/ubuntu oracular/universe asterisk 1:20.6.0~dfsg+~cs6.13.40431414-2build5 (tar) [22.5 kB] 188s Get:5 http://ftpmaster.internal/ubuntu oracular/universe asterisk 1:20.6.0~dfsg+~cs6.13.40431414-2build5 (tar) [5841 kB] 188s Get:6 http://ftpmaster.internal/ubuntu oracular/universe asterisk 1:20.6.0~dfsg+~cs6.13.40431414-2build5 (tar) [7300 kB] 188s Get:7 http://ftpmaster.internal/ubuntu oracular/universe asterisk 1:20.6.0~dfsg+~cs6.13.40431414-2build5 (diff) [135 kB] 188s gpgv: Signature made Mon Apr 15 00:13:34 2024 UTC 188s gpgv: using RSA key AC0A4FF12611B6FCCF01C111393587D97D86500B 188s gpgv: Can't check signature: No public key 188s dpkg-source: warning: cannot verify inline signature for ./asterisk_20.6.0~dfsg+~cs6.13.40431414-2build5.dsc: no acceptable signature found 190s autopkgtest [13:15:52]: testing package asterisk version 1:20.6.0~dfsg+~cs6.13.40431414-2build5 190s autopkgtest [13:15:52]: build not needed 207s autopkgtest [13:16:09]: test asttestmods: preparing testbed 210s Reading package lists... 210s Building dependency tree... 210s Reading state information... 210s Starting pkgProblemResolver with broken count: 0 210s Starting 2 pkgProblemResolver with broken count: 0 210s Done 211s The following additional packages will be installed: 211s asterisk asterisk-config asterisk-core-sounds-en asterisk-core-sounds-en-gsm 211s asterisk-modules asterisk-tests freetds-common libasound2-data libasound2t64 211s libc-client2007e libcodec2-1.2 libevent-2.1-7t64 libgmime-3.0-0t64 libgsm1 211s libical3t64 libiksemel3 libjack-jackd2-0 libltdl7 liblua5.1-0 libneon27t64 211s libodbc2 libogg0 libopencore-amrnb0 libopencore-amrwb0 libopus0 libopusenc0 211s libopusfile0 libportaudio2 libpq5 libradcli4 libresample1 libsamplerate0 211s libsnmp-base libsnmp40t64 libspandsp2t64 libspeex1 libspeexdsp1 libsrtp2-1 211s libsybdb5 libunbound8 liburiparser1 libvo-amrwbenc0 libvorbis0a 211s libvorbisenc2 libvorbisfile3 libxml2-utils libxslt1.1 mlock 211s Suggested packages: 211s asterisk-dahdi asterisk-dev asterisk-doc asterisk-ooh323 asterisk-opus 211s alsa-utils libasound2-plugins uw-mailutils jackd2 odbc-postgresql tdsodbc 211s opus-tools snmp-mibs-downloader speex 211s Recommended packages: 211s asterisk-moh-opsound-gsm sox alsa-ucm-conf alsa-topology-conf 211s The following NEW packages will be installed: 211s asterisk asterisk-config asterisk-core-sounds-en asterisk-core-sounds-en-gsm 211s asterisk-modules asterisk-tests autopkgtest-satdep freetds-common 211s libasound2-data libasound2t64 libc-client2007e libcodec2-1.2 211s libevent-2.1-7t64 libgmime-3.0-0t64 libgsm1 libical3t64 libiksemel3 211s libjack-jackd2-0 libltdl7 liblua5.1-0 libneon27t64 libodbc2 libogg0 211s libopencore-amrnb0 libopencore-amrwb0 libopus0 libopusenc0 libopusfile0 211s libportaudio2 libpq5 libradcli4 libresample1 libsamplerate0 libsnmp-base 211s libsnmp40t64 libspandsp2t64 libspeex1 libspeexdsp1 libsrtp2-1 libsybdb5 211s libunbound8 liburiparser1 libvo-amrwbenc0 libvorbis0a libvorbisenc2 211s libvorbisfile3 libxml2-utils libxslt1.1 mlock 211s 0 upgraded, 49 newly installed, 0 to remove and 0 not upgraded. 211s Need to get 27.3 MB/27.3 MB of archives. 211s After this operation, 97.5 MB of additional disk space will be used. 211s Get:1 /tmp/autopkgtest.DVfJk3/1-autopkgtest-satdep.deb autopkgtest-satdep ppc64el 0 [744 B] 211s Get:2 http://ftpmaster.internal/ubuntu oracular/universe ppc64el asterisk-config all 1:20.6.0~dfsg+~cs6.13.40431414-2build5 [242 kB] 211s Get:3 http://ftpmaster.internal/ubuntu oracular/universe ppc64el asterisk-core-sounds-en-gsm all 1.6.1-1 [2417 kB] 211s Get:4 http://ftpmaster.internal/ubuntu oracular/universe ppc64el asterisk-core-sounds-en all 1.6.1-1 [20.6 kB] 211s Get:5 http://ftpmaster.internal/ubuntu oracular/universe ppc64el mlock ppc64el 8:2007f~dfsg-7build3 [8082 B] 211s Get:6 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libc-client2007e ppc64el 8:2007f~dfsg-7build3 [676 kB] 212s Get:7 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libcodec2-1.2 ppc64el 1.2.0-2build1 [9048 kB] 212s Get:8 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libgmime-3.0-0t64 ppc64el 3.2.14+dfsg-2 [206 kB] 212s Get:9 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libgsm1 ppc64el 1.0.22-1build1 [41.9 kB] 212s Get:10 http://ftpmaster.internal/ubuntu oracular/main ppc64el libical3t64 ppc64el 3.0.18-1 [345 kB] 212s Get:11 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libiksemel3 ppc64el 1.4-4build2 [34.8 kB] 212s Get:12 http://ftpmaster.internal/ubuntu oracular/main ppc64el libopus0 ppc64el 1.4-1build1 [322 kB] 212s Get:13 http://ftpmaster.internal/ubuntu oracular/main ppc64el libsamplerate0 ppc64el 0.2.2-4build1 [1348 kB] 212s Get:14 http://ftpmaster.internal/ubuntu oracular/main ppc64el libjack-jackd2-0 ppc64el 1.9.21~dfsg-3ubuntu3 [340 kB] 212s Get:15 http://ftpmaster.internal/ubuntu oracular/universe ppc64el liblua5.1-0 ppc64el 5.1.5-9build2 [157 kB] 212s Get:16 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libneon27t64 ppc64el 0.33.0-1.1build3 [120 kB] 212s Get:17 http://ftpmaster.internal/ubuntu oracular/main ppc64el libltdl7 ppc64el 2.4.7-7build1 [48.2 kB] 212s Get:18 http://ftpmaster.internal/ubuntu oracular/main ppc64el libodbc2 ppc64el 2.3.12-1build2 [188 kB] 212s Get:19 http://ftpmaster.internal/ubuntu oracular/main ppc64el libogg0 ppc64el 1.3.5-3build1 [27.6 kB] 212s Get:20 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libopencore-amrnb0 ppc64el 0.1.6-1build1 [165 kB] 212s Get:21 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libopencore-amrwb0 ppc64el 0.1.6-1build1 [91.2 kB] 212s Get:22 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libopusenc0 ppc64el 0.2.1-2build1 [34.5 kB] 212s Get:23 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libopusfile0 ppc64el 0.12-4build3 [60.6 kB] 212s Get:24 http://ftpmaster.internal/ubuntu oracular/main ppc64el libasound2-data all 1.2.11-1build2 [21.0 kB] 212s Get:25 http://ftpmaster.internal/ubuntu oracular/main ppc64el libasound2t64 ppc64el 1.2.11-1build2 [502 kB] 212s Get:26 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libportaudio2 ppc64el 19.6.0-1.2build3 [87.5 kB] 212s Get:27 http://ftpmaster.internal/ubuntu oracular/main ppc64el libpq5 ppc64el 16.3-1 [171 kB] 212s Get:28 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libradcli4 ppc64el 1.2.11-1build3 [45.5 kB] 212s Get:29 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libresample1 ppc64el 0.1.3-6 [11.1 kB] 212s Get:30 http://ftpmaster.internal/ubuntu oracular/main ppc64el libsnmp-base all 5.9.4+dfsg-1.1ubuntu3 [206 kB] 212s Get:31 http://ftpmaster.internal/ubuntu oracular/main ppc64el libsnmp40t64 ppc64el 5.9.4+dfsg-1.1ubuntu3 [1206 kB] 212s Get:32 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libspandsp2t64 ppc64el 0.0.6+dfsg-2.1build1 [399 kB] 212s Get:33 http://ftpmaster.internal/ubuntu oracular/main ppc64el libspeex1 ppc64el 1.2.1-2ubuntu2 [111 kB] 212s Get:34 http://ftpmaster.internal/ubuntu oracular/main ppc64el libspeexdsp1 ppc64el 1.2.1-1ubuntu3 [75.0 kB] 212s Get:35 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libsrtp2-1 ppc64el 2.5.0-3build1 [51.4 kB] 212s Get:36 http://ftpmaster.internal/ubuntu oracular/main ppc64el freetds-common all 1.3.17+ds-2build3 [26.9 kB] 212s Get:37 http://ftpmaster.internal/ubuntu oracular/main ppc64el libsybdb5 ppc64el 1.3.17+ds-2build3 [238 kB] 212s Get:38 http://ftpmaster.internal/ubuntu oracular/main ppc64el libevent-2.1-7t64 ppc64el 2.1.12-stable-10 [172 kB] 212s Get:39 http://ftpmaster.internal/ubuntu oracular/main ppc64el libunbound8 ppc64el 1.19.2-1ubuntu3 [537 kB] 212s Get:40 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libvo-amrwbenc0 ppc64el 0.1.3-2build1 [126 kB] 212s Get:41 http://ftpmaster.internal/ubuntu oracular/main ppc64el libvorbis0a ppc64el 1.3.7-2 [142 kB] 212s Get:42 http://ftpmaster.internal/ubuntu oracular/main ppc64el libvorbisenc2 ppc64el 1.3.7-2 [86.2 kB] 212s Get:43 http://ftpmaster.internal/ubuntu oracular/main ppc64el libvorbisfile3 ppc64el 1.3.7-2 [22.5 kB] 212s Get:44 http://ftpmaster.internal/ubuntu oracular/universe ppc64el asterisk-modules ppc64el 1:20.6.0~dfsg+~cs6.13.40431414-2build5 [3407 kB] 212s Get:45 http://ftpmaster.internal/ubuntu oracular/universe ppc64el liburiparser1 ppc64el 0.9.7+dfsg-2build1 [53.6 kB] 212s Get:46 http://ftpmaster.internal/ubuntu oracular/main ppc64el libxslt1.1 ppc64el 1.1.39-0exp1build1 [192 kB] 212s Get:47 http://ftpmaster.internal/ubuntu oracular/universe ppc64el asterisk ppc64el 1:20.6.0~dfsg+~cs6.13.40431414-2build5 [2812 kB] 213s Get:48 http://ftpmaster.internal/ubuntu oracular/universe ppc64el asterisk-tests ppc64el 1:20.6.0~dfsg+~cs6.13.40431414-2build5 [576 kB] 213s Get:49 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el libxml2-utils ppc64el 2.12.7+dfsg-3 [42.7 kB] 213s Fetched 27.3 MB in 2s (15.7 MB/s) 213s Selecting previously unselected package asterisk-config. 213s (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 ... 72596 files and directories currently installed.) 213s Preparing to unpack .../00-asterisk-config_1%3a20.6.0~dfsg+~cs6.13.40431414-2build5_all.deb ... 213s Unpacking asterisk-config (1:20.6.0~dfsg+~cs6.13.40431414-2build5) ... 213s Selecting previously unselected package asterisk-core-sounds-en-gsm. 213s Preparing to unpack .../01-asterisk-core-sounds-en-gsm_1.6.1-1_all.deb ... 213s Unpacking asterisk-core-sounds-en-gsm (1.6.1-1) ... 213s Selecting previously unselected package asterisk-core-sounds-en. 213s Preparing to unpack .../02-asterisk-core-sounds-en_1.6.1-1_all.deb ... 213s Unpacking asterisk-core-sounds-en (1.6.1-1) ... 213s Selecting previously unselected package mlock. 213s Preparing to unpack .../03-mlock_8%3a2007f~dfsg-7build3_ppc64el.deb ... 213s Unpacking mlock (8:2007f~dfsg-7build3) ... 213s Selecting previously unselected package libc-client2007e. 213s Preparing to unpack .../04-libc-client2007e_8%3a2007f~dfsg-7build3_ppc64el.deb ... 213s Unpacking libc-client2007e (8:2007f~dfsg-7build3) ... 213s Selecting previously unselected package libcodec2-1.2:ppc64el. 213s Preparing to unpack .../05-libcodec2-1.2_1.2.0-2build1_ppc64el.deb ... 213s Unpacking libcodec2-1.2:ppc64el (1.2.0-2build1) ... 213s Selecting previously unselected package libgmime-3.0-0t64:ppc64el. 213s Preparing to unpack .../06-libgmime-3.0-0t64_3.2.14+dfsg-2_ppc64el.deb ... 213s Unpacking libgmime-3.0-0t64:ppc64el (3.2.14+dfsg-2) ... 213s Selecting previously unselected package libgsm1:ppc64el. 213s Preparing to unpack .../07-libgsm1_1.0.22-1build1_ppc64el.deb ... 213s Unpacking libgsm1:ppc64el (1.0.22-1build1) ... 213s Selecting previously unselected package libical3t64:ppc64el. 213s Preparing to unpack .../08-libical3t64_3.0.18-1_ppc64el.deb ... 213s Unpacking libical3t64:ppc64el (3.0.18-1) ... 213s Selecting previously unselected package libiksemel3:ppc64el. 213s Preparing to unpack .../09-libiksemel3_1.4-4build2_ppc64el.deb ... 213s Unpacking libiksemel3:ppc64el (1.4-4build2) ... 213s Selecting previously unselected package libopus0:ppc64el. 213s Preparing to unpack .../10-libopus0_1.4-1build1_ppc64el.deb ... 213s Unpacking libopus0:ppc64el (1.4-1build1) ... 214s Selecting previously unselected package libsamplerate0:ppc64el. 214s Preparing to unpack .../11-libsamplerate0_0.2.2-4build1_ppc64el.deb ... 214s Unpacking libsamplerate0:ppc64el (0.2.2-4build1) ... 214s Selecting previously unselected package libjack-jackd2-0:ppc64el. 214s Preparing to unpack .../12-libjack-jackd2-0_1.9.21~dfsg-3ubuntu3_ppc64el.deb ... 214s Unpacking libjack-jackd2-0:ppc64el (1.9.21~dfsg-3ubuntu3) ... 214s Selecting previously unselected package liblua5.1-0:ppc64el. 214s Preparing to unpack .../13-liblua5.1-0_5.1.5-9build2_ppc64el.deb ... 214s Unpacking liblua5.1-0:ppc64el (5.1.5-9build2) ... 214s Selecting previously unselected package libneon27t64:ppc64el. 214s Preparing to unpack .../14-libneon27t64_0.33.0-1.1build3_ppc64el.deb ... 214s Unpacking libneon27t64:ppc64el (0.33.0-1.1build3) ... 214s Selecting previously unselected package libltdl7:ppc64el. 214s Preparing to unpack .../15-libltdl7_2.4.7-7build1_ppc64el.deb ... 214s Unpacking libltdl7:ppc64el (2.4.7-7build1) ... 214s Selecting previously unselected package libodbc2:ppc64el. 214s Preparing to unpack .../16-libodbc2_2.3.12-1build2_ppc64el.deb ... 214s Unpacking libodbc2:ppc64el (2.3.12-1build2) ... 214s Selecting previously unselected package libogg0:ppc64el. 214s Preparing to unpack .../17-libogg0_1.3.5-3build1_ppc64el.deb ... 214s Unpacking libogg0:ppc64el (1.3.5-3build1) ... 214s Selecting previously unselected package libopencore-amrnb0:ppc64el. 214s Preparing to unpack .../18-libopencore-amrnb0_0.1.6-1build1_ppc64el.deb ... 214s Unpacking libopencore-amrnb0:ppc64el (0.1.6-1build1) ... 214s Selecting previously unselected package libopencore-amrwb0:ppc64el. 214s Preparing to unpack .../19-libopencore-amrwb0_0.1.6-1build1_ppc64el.deb ... 214s Unpacking libopencore-amrwb0:ppc64el (0.1.6-1build1) ... 214s Selecting previously unselected package libopusenc0:ppc64el. 214s Preparing to unpack .../20-libopusenc0_0.2.1-2build1_ppc64el.deb ... 214s Unpacking libopusenc0:ppc64el (0.2.1-2build1) ... 214s Selecting previously unselected package libopusfile0:ppc64el. 214s Preparing to unpack .../21-libopusfile0_0.12-4build3_ppc64el.deb ... 214s Unpacking libopusfile0:ppc64el (0.12-4build3) ... 214s Selecting previously unselected package libasound2-data. 214s Preparing to unpack .../22-libasound2-data_1.2.11-1build2_all.deb ... 214s Unpacking libasound2-data (1.2.11-1build2) ... 214s Selecting previously unselected package libasound2t64:ppc64el. 214s Preparing to unpack .../23-libasound2t64_1.2.11-1build2_ppc64el.deb ... 214s Unpacking libasound2t64:ppc64el (1.2.11-1build2) ... 214s Selecting previously unselected package libportaudio2:ppc64el. 214s Preparing to unpack .../24-libportaudio2_19.6.0-1.2build3_ppc64el.deb ... 214s Unpacking libportaudio2:ppc64el (19.6.0-1.2build3) ... 214s Selecting previously unselected package libpq5:ppc64el. 214s Preparing to unpack .../25-libpq5_16.3-1_ppc64el.deb ... 214s Unpacking libpq5:ppc64el (16.3-1) ... 214s Selecting previously unselected package libradcli4. 214s Preparing to unpack .../26-libradcli4_1.2.11-1build3_ppc64el.deb ... 214s Unpacking libradcli4 (1.2.11-1build3) ... 214s Selecting previously unselected package libresample1. 214s Preparing to unpack .../27-libresample1_0.1.3-6_ppc64el.deb ... 214s Unpacking libresample1 (0.1.3-6) ... 214s Selecting previously unselected package libsnmp-base. 214s Preparing to unpack .../28-libsnmp-base_5.9.4+dfsg-1.1ubuntu3_all.deb ... 214s Unpacking libsnmp-base (5.9.4+dfsg-1.1ubuntu3) ... 214s Selecting previously unselected package libsnmp40t64:ppc64el. 214s Preparing to unpack .../29-libsnmp40t64_5.9.4+dfsg-1.1ubuntu3_ppc64el.deb ... 214s Unpacking libsnmp40t64:ppc64el (5.9.4+dfsg-1.1ubuntu3) ... 214s Selecting previously unselected package libspandsp2t64:ppc64el. 214s Preparing to unpack .../30-libspandsp2t64_0.0.6+dfsg-2.1build1_ppc64el.deb ... 214s Unpacking libspandsp2t64:ppc64el (0.0.6+dfsg-2.1build1) ... 214s Selecting previously unselected package libspeex1:ppc64el. 214s Preparing to unpack .../31-libspeex1_1.2.1-2ubuntu2_ppc64el.deb ... 214s Unpacking libspeex1:ppc64el (1.2.1-2ubuntu2) ... 214s Selecting previously unselected package libspeexdsp1:ppc64el. 214s Preparing to unpack .../32-libspeexdsp1_1.2.1-1ubuntu3_ppc64el.deb ... 214s Unpacking libspeexdsp1:ppc64el (1.2.1-1ubuntu3) ... 214s Selecting previously unselected package libsrtp2-1:ppc64el. 214s Preparing to unpack .../33-libsrtp2-1_2.5.0-3build1_ppc64el.deb ... 214s Unpacking libsrtp2-1:ppc64el (2.5.0-3build1) ... 214s Selecting previously unselected package freetds-common. 214s Preparing to unpack .../34-freetds-common_1.3.17+ds-2build3_all.deb ... 214s Unpacking freetds-common (1.3.17+ds-2build3) ... 214s Selecting previously unselected package libsybdb5:ppc64el. 214s Preparing to unpack .../35-libsybdb5_1.3.17+ds-2build3_ppc64el.deb ... 214s Unpacking libsybdb5:ppc64el (1.3.17+ds-2build3) ... 214s Selecting previously unselected package libevent-2.1-7t64:ppc64el. 214s Preparing to unpack .../36-libevent-2.1-7t64_2.1.12-stable-10_ppc64el.deb ... 214s Unpacking libevent-2.1-7t64:ppc64el (2.1.12-stable-10) ... 214s Selecting previously unselected package libunbound8:ppc64el. 214s Preparing to unpack .../37-libunbound8_1.19.2-1ubuntu3_ppc64el.deb ... 214s Unpacking libunbound8:ppc64el (1.19.2-1ubuntu3) ... 214s Selecting previously unselected package libvo-amrwbenc0:ppc64el. 214s Preparing to unpack .../38-libvo-amrwbenc0_0.1.3-2build1_ppc64el.deb ... 214s Unpacking libvo-amrwbenc0:ppc64el (0.1.3-2build1) ... 214s Selecting previously unselected package libvorbis0a:ppc64el. 214s Preparing to unpack .../39-libvorbis0a_1.3.7-2_ppc64el.deb ... 214s Unpacking libvorbis0a:ppc64el (1.3.7-2) ... 214s Selecting previously unselected package libvorbisenc2:ppc64el. 214s Preparing to unpack .../40-libvorbisenc2_1.3.7-2_ppc64el.deb ... 214s Unpacking libvorbisenc2:ppc64el (1.3.7-2) ... 214s Selecting previously unselected package libvorbisfile3:ppc64el. 214s Preparing to unpack .../41-libvorbisfile3_1.3.7-2_ppc64el.deb ... 214s Unpacking libvorbisfile3:ppc64el (1.3.7-2) ... 214s Selecting previously unselected package asterisk-modules. 214s Preparing to unpack .../42-asterisk-modules_1%3a20.6.0~dfsg+~cs6.13.40431414-2build5_ppc64el.deb ... 214s Unpacking asterisk-modules (1:20.6.0~dfsg+~cs6.13.40431414-2build5) ... 214s Selecting previously unselected package liburiparser1:ppc64el. 214s Preparing to unpack .../43-liburiparser1_0.9.7+dfsg-2build1_ppc64el.deb ... 214s Unpacking liburiparser1:ppc64el (0.9.7+dfsg-2build1) ... 214s Selecting previously unselected package libxslt1.1:ppc64el. 214s Preparing to unpack .../44-libxslt1.1_1.1.39-0exp1build1_ppc64el.deb ... 214s Unpacking libxslt1.1:ppc64el (1.1.39-0exp1build1) ... 214s Selecting previously unselected package asterisk. 214s Preparing to unpack .../45-asterisk_1%3a20.6.0~dfsg+~cs6.13.40431414-2build5_ppc64el.deb ... 214s Unpacking asterisk (1:20.6.0~dfsg+~cs6.13.40431414-2build5) ... 215s Selecting previously unselected package asterisk-tests. 215s Preparing to unpack .../46-asterisk-tests_1%3a20.6.0~dfsg+~cs6.13.40431414-2build5_ppc64el.deb ... 215s Unpacking asterisk-tests (1:20.6.0~dfsg+~cs6.13.40431414-2build5) ... 215s Selecting previously unselected package libxml2-utils. 215s Preparing to unpack .../47-libxml2-utils_2.12.7+dfsg-3_ppc64el.deb ... 215s Unpacking libxml2-utils (2.12.7+dfsg-3) ... 215s Selecting previously unselected package autopkgtest-satdep. 215s Preparing to unpack .../48-1-autopkgtest-satdep.deb ... 215s Unpacking autopkgtest-satdep (0) ... 215s Setting up libvo-amrwbenc0:ppc64el (0.1.3-2build1) ... 215s Setting up libneon27t64:ppc64el (0.33.0-1.1build3) ... 215s Setting up libogg0:ppc64el (1.3.5-3build1) ... 215s Setting up libspeex1:ppc64el (1.2.1-2ubuntu2) ... 215s Setting up libgsm1:ppc64el (1.0.22-1build1) ... 215s Setting up asterisk-core-sounds-en-gsm (1.6.1-1) ... 215s Setting up libsnmp-base (5.9.4+dfsg-1.1ubuntu3) ... 215s Setting up libcodec2-1.2:ppc64el (1.2.0-2build1) ... 215s Setting up mlock (8:2007f~dfsg-7build3) ... 215s Setting up libsrtp2-1:ppc64el (2.5.0-3build1) ... 215s Setting up libpq5:ppc64el (16.3-1) ... 215s Setting up libevent-2.1-7t64:ppc64el (2.1.12-stable-10) ... 215s Setting up libasound2-data (1.2.11-1build2) ... 215s Setting up libopencore-amrwb0:ppc64el (0.1.6-1build1) ... 215s Setting up libunbound8:ppc64el (1.19.2-1ubuntu3) ... 215s Setting up libasound2t64:ppc64el (1.2.11-1build2) ... 215s Setting up libradcli4 (1.2.11-1build3) ... 215s Setting up libopus0:ppc64el (1.4-1build1) ... 215s Setting up asterisk-config (1:20.6.0~dfsg+~cs6.13.40431414-2build5) ... 215s Setting up libvorbis0a:ppc64el (1.3.7-2) ... 215s Setting up libical3t64:ppc64el (3.0.18-1) ... 215s Setting up libltdl7:ppc64el (2.4.7-7build1) ... 215s Setting up asterisk-core-sounds-en (1.6.1-1) ... 215s update-alternatives: using /usr/share/asterisk/sounds/en_US_f_Allison to provide /usr/share/asterisk/sounds/en (asterisk-prompt-en) in auto mode 215s 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 215s Setting up libiksemel3:ppc64el (1.4-4build2) ... 215s Setting up libodbc2:ppc64el (2.3.12-1build2) ... 215s Setting up liburiparser1:ppc64el (0.9.7+dfsg-2build1) ... 215s Setting up libspandsp2t64:ppc64el (0.0.6+dfsg-2.1build1) ... 215s Setting up libspeexdsp1:ppc64el (1.2.1-1ubuntu3) ... 215s Setting up liblua5.1-0:ppc64el (5.1.5-9build2) ... 215s Setting up libxslt1.1:ppc64el (1.1.39-0exp1build1) ... 215s Setting up libopencore-amrnb0:ppc64el (0.1.6-1build1) ... 215s Setting up libc-client2007e (8:2007f~dfsg-7build3) ... 215s Setting up libresample1 (0.1.3-6) ... 215s Setting up freetds-common (1.3.17+ds-2build3) ... 215s Setting up libxml2-utils (2.12.7+dfsg-3) ... 215s Setting up libgmime-3.0-0t64:ppc64el (3.2.14+dfsg-2) ... 215s Setting up libsamplerate0:ppc64el (0.2.2-4build1) ... 215s Setting up libopusfile0:ppc64el (0.12-4build3) ... 215s Setting up libvorbisenc2:ppc64el (1.3.7-2) ... 215s Setting up libopusenc0:ppc64el (0.2.1-2build1) ... 215s Setting up libsnmp40t64:ppc64el (5.9.4+dfsg-1.1ubuntu3) ... 215s Setting up libsybdb5:ppc64el (1.3.17+ds-2build3) ... 215s Setting up libvorbisfile3:ppc64el (1.3.7-2) ... 215s Setting up libjack-jackd2-0:ppc64el (1.9.21~dfsg-3ubuntu3) ... 215s Setting up libportaudio2:ppc64el (19.6.0-1.2build3) ... 215s Setting up asterisk-modules (1:20.6.0~dfsg+~cs6.13.40431414-2build5) ... 215s Setting up asterisk (1:20.6.0~dfsg+~cs6.13.40431414-2build5) ... 215s Adding system user for Asterisk 215s info: Adding user `asterisk' to group `dialout' ... 215s info: Adding user `asterisk' to group `audio' ... 216s Created symlink /etc/systemd/system/multi-user.target.wants/asterisk.service → /usr/lib/systemd/system/asterisk.service. 217s Setting up asterisk-tests (1:20.6.0~dfsg+~cs6.13.40431414-2build5) ... 217s Setting up autopkgtest-satdep (0) ... 217s Processing triggers for man-db (2.12.1-1) ... 218s Processing triggers for libc-bin (2.39-0ubuntu8.1) ... 223s (Reading database ... 74625 files and directories currently installed.) 223s Removing autopkgtest-satdep (0) ... 224s autopkgtest [13:16:26]: test asttestmods: [----------------------- 224s dpkg-architecture: warning: cannot determine CC system type, falling back to default (native compilation) 226s 'U' option is not compatible with remote console mode and has no effect. 226s 226s Asterisk has fully booted. 226s 'U' option is not compatible with remote console mode and has no effect. 226s 226s Running all available tests... 226s 226s START /apps/app_gosub/ - gosub application 226s END /apps/app_gosub/ - gosub application Time: <1ms Result: PASS 226s START /apps/app_voicemail/ - test_voicemail_vm_info 226s END /apps/app_voicemail/ - test_voicemail_vm_info Time: <1ms Result: PASS 226s START /apps/app_voicemail/ - test_voicemail_load_config 226s END /apps/app_voicemail/ - test_voicemail_load_config Time: <1ms Result: PASS 226s START /apps/app_voicemail/ - test_voicemail_notify_endl 226s END /apps/app_voicemail/ - test_voicemail_notify_endl Time: 6ms Result: PASS 226s START /apps/app_voicemail/ - vmuser 226s END /apps/app_voicemail/ - vmuser Time: <1ms Result: PASS 226s START /apps/app_voicemail/ - test_voicemail_msgcount 226s END /apps/app_voicemail/ - test_voicemail_msgcount Time: 41ms Result: PASS 226s START /apps/app_voicemail/ - vmsayname_exec 226s [app_voicemail.c:test_voicemail_vmsayname:15218]: Test playing of extension when greeting is not available... 230s [app_voicemail.c:test_voicemail_vmsayname:15239]: Test playing created mailbox greeting... 235s END /apps/app_voicemail/ - vmsayname_exec Time: 8888ms Result: PASS 235s START /ari/validators/ - validate_list 235s END /ari/validators/ - validate_list Time: <1ms Result: PASS 235s START /ari/validators/ - validate_date 235s END /ari/validators/ - validate_date Time: <1ms Result: PASS 235s START /ari/validators/ - validate_string 235s END /ari/validators/ - validate_string Time: <1ms Result: PASS 235s START /ari/validators/ - validate_long 235s END /ari/validators/ - validate_long Time: <1ms Result: PASS 235s START /ari/validators/ - validate_int 235s END /ari/validators/ - validate_int Time: <1ms Result: PASS 235s START /ari/validators/ - validate_boolean 235s END /ari/validators/ - validate_boolean Time: <1ms Result: PASS 235s START /ari/validators/ - validate_byte 235s END /ari/validators/ - validate_byte Time: <1ms Result: PASS 235s START /bridges/bridge_softmix/ - sfu_remove_destination_streams 235s END /bridges/bridge_softmix/ - sfu_remove_destination_streams Time: <1ms Result: PASS 235s START /bridges/bridge_softmix/ - sfu_append_source_streams 235s END /bridges/bridge_softmix/ - sfu_append_source_streams Time: <1ms Result: PASS 235s START /channels/features/ - test_features_channel_interval 238s END /channels/features/ - test_features_channel_interval Time: 3003ms Result: PASS 238s START /channels/features/ - test_features_channel_dtmf 240s END /channels/features/ - test_features_channel_dtmf Time: 2010ms Result: PASS 240s START /config/ - config_options_test 240s END /config/ - config_options_test Time: <1ms Result: PASS 240s START /config/ - ast_parse_arg 240s END /config/ - ast_parse_arg Time: <1ms Result: PASS 240s START /core/endpoints/ - setters 240s END /core/endpoints/ - setters Time: <1ms Result: PASS 240s START /core/endpoints/ - defaults 240s END /core/endpoints/ - defaults Time: <1ms Result: PASS 240s START /core/endpoints/ - create 240s END /core/endpoints/ - create Time: <1ms Result: PASS 240s START /funcs/func_curl/ - vulnerable_url 240s END /funcs/func_curl/ - vulnerable_url Time: <1ms Result: PASS 240s START /funcs/func_env/ - func_file 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,1)=a'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-9,1)=a'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,-8)=a'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-9,-8)=a'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,5,1)=b'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-4,1)=b'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,5,-3)=b'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-4,-3)=b'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,2)=c'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-9,2)=c'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,-7)=c'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-9,-7)=c'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,4,2)=d'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-5,2)=d'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,4,-3)=d'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-5,-3)=d'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,5)=e'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,5)='... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-4)=e'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-4)='... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,1)=fg'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,-8)=fg'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-9,1)=fg'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-9,-8)=fg'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,)=h'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,,,,)=h'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,,,l)=h'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,,,ld)=h'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,1,l)=abc'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,1,l)=abc'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,-2,l)=abc'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,-2,l)=abc'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,1,l)=abc'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,-1,l)=abc'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,1,l)=abc'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,-1,l)=abc'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,1,l)=ab'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,1,l)=ab'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,-2,l)=ab'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,-2,l)=ab'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,1,l)=ab'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,-1,l)=ab'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,1,l)=ab'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,-1,l)=ab'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,1,l)=abcd'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,1,l)=abcd'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,-2,l)=abcd'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,-2,l)=abcd'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,1,l)=abcd'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,-1,l)=abcd'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,1,l)=abcd'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,-1,l)=abcd'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,2,l)=abcdefg'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,2,l)=abcdefg'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,-1,l)=abcdefg'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,-1,l)=abcdefg'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,2,l)=abcdefg'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,,l)=abcdefg'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,2,l)=abcdefg'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,,l)=abcdefg'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,2,l)=abcd'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,2,l)=abcd'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,-1,l)=abcd'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,-1,l)=abcd'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,2,l)=abcd'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,,l)=abcd'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,2,l)=abcd'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,,l)=abcd'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,2,l)=abcdefghijklmnop'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,2,l)=abcdefghijklmnop'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,-1,l)=abcdefghijklmnop'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,-1,l)=abcdefghijklmnop'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,2,l)=abcdefghijklmnop'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,,l)=abcdefghijklmnop'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,2,l)=abcdefghijklmnop'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,,l)=abcdefghijklmnop'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,0,l)=abcd'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,0,l)=abcd'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,0,l)=abcd'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,0,l)=abcd'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,2,0,l)=abcd'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-1,0,l)=abcd'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,3,0,l)=abcd'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,,,la)=abcd'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,1,l)='... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,1,l)='... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,-2,l)='... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,-2,l)='... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,1,l)='... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,-1,l)='... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,1,l)='... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,-1,l)='... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,1,ld)='... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,1,ld)='... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,-2,ld)='... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,-2,ld)='... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,1,ld)='... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,-1,ld)='... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,1,ld)='... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,-1,ld)='... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,1)=a'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,1)=abcd'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,10)=abcd'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,1,l)=abcd'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,1,l)=abcd'... OK! 240s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,1,l)=a'... OK! 240s END /funcs/func_env/ - func_file Time: 29ms Result: PASS 240s START /funcs/func_json/ - func_JSON_DECODE 240s END /funcs/func_json/ - func_JSON_DECODE Time: <1ms Result: PASS 240s START /funcs/func_presence/ - test_presence_state_base64_encode 240s END /funcs/func_presence/ - test_presence_state_base64_encode Time: 2ms Result: PASS 240s START /funcs/func_presence/ - test_presence_state_change 240s END /funcs/func_presence/ - test_presence_state_change Time: <1ms Result: PASS 240s START /funcs/func_presence/ - parse_invalid_presence_data 240s END /funcs/func_presence/ - parse_invalid_presence_data Time: <1ms Result: PASS 240s START /funcs/func_presence/ - parse_valid_presence_data 240s END /funcs/func_presence/ - parse_valid_presence_data Time: <1ms Result: PASS 240s START /funcs/func_sayfiles/ - test_SAYFILES_function 240s [func_sayfiles.c:test_SAYFILES_function:180]: Testing SAYFILES() substitution ... 240s END /funcs/func_sayfiles/ - test_SAYFILES_function Time: 7ms Result: PASS 240s START /funcs/func_strings/ - func_TRIM 240s END /funcs/func_strings/ - func_TRIM Time: <1ms Result: PASS 240s START /funcs/func_strings/ - func_STRBETWEEN 240s END /funcs/func_strings/ - func_STRBETWEEN Time: <1ms Result: PASS 240s START /funcs/func_strings/ - func_STRREPLACE_test 240s END /funcs/func_strings/ - func_STRREPLACE_test Time: <1ms Result: PASS 240s START /funcs/func_strings/ - func_FILTER_test 240s END /funcs/func_strings/ - func_FILTER_test Time: <1ms Result: PASS 240s START /funcs/func_strings/ - func_REPLACE_test 240s END /funcs/func_strings/ - func_REPLACE_test Time: <1ms Result: PASS 240s START /funcs/func_strings/ - func_FIELDNUM_test 240s END /funcs/func_strings/ - func_FIELDNUM_test Time: <1ms Result: PASS 240s START /geoloc/ - create_from_pidf 240s [res_geolocation/geoloc_eprofile.c:validate_eprofile:1274]: ID: 'point-2d' pidf_element: 'tuple' format: 'GML' method: 'Manual' 240s [res_geolocation/geoloc_eprofile.c:validate_eprofile:1286]: location_vars expected: shape=Point,crs=2d,pos=-34.410649 150.87651 240s [res_geolocation/geoloc_eprofile.c:validate_eprofile:1287]: location_vars received: shape=Point,crs=2d,pos=-34.410649 150.87651 240s [res_geolocation/geoloc_eprofile.c:validate_eprofile:1293]: usage_rules expected: retransmission-allowed='no',retention-expiry='2010-11-14T20:00:00Z' 240s [res_geolocation/geoloc_eprofile.c:validate_eprofile:1294]: usage_rules received: retransmission-allowed='no',retention-expiry='2010-11-14T20:00:00Z' 240s END /geoloc/ - create_from_pidf Time: <1ms Result: PASS 240s START /geoloc/ - create_from_uri 240s END /geoloc/ - create_from_uri Time: <1ms Result: PASS 240s START /main/abstract_jb/ - AST_JB_FIXED_put_out_of_order 240s [test_abstract_jb.c:AST_JB_FIXED_put_out_of_order:531]: Executing AST_JB_FIXED_put_out_of_order... 240s END /main/abstract_jb/ - AST_JB_FIXED_put_out_of_order Time: <1ms Result: PASS 240s START /main/abstract_jb/ - AST_JB_FIXED_put_overflow 240s [test_abstract_jb.c:AST_JB_FIXED_put_overflow:529]: Executing AST_JB_FIXED_put_overflow... 240s END /main/abstract_jb/ - AST_JB_FIXED_put_overflow Time: <1ms Result: PASS 240s START /main/abstract_jb/ - AST_JB_FIXED_put 240s [test_abstract_jb.c:AST_JB_FIXED_put:527]: Executing AST_JB_FIXED_put... 240s END /main/abstract_jb/ - AST_JB_FIXED_put Time: <1ms Result: PASS 240s START /main/abstract_jb/ - AST_JB_FIXED_put_first 240s [test_abstract_jb.c:AST_JB_FIXED_put_first:525]: Executing AST_JB_FIXED_create... 240s END /main/abstract_jb/ - AST_JB_FIXED_put_first Time: <1ms Result: PASS 240s START /main/abstract_jb/ - AST_JB_FIXED_create 240s [test_abstract_jb.c:AST_JB_FIXED_create:523]: Executing AST_JB_FIXED_create... 240s END /main/abstract_jb/ - AST_JB_FIXED_create Time: <1ms Result: PASS 240s START /main/abstract_jb/ - AST_JB_ADAPTIVE_put_out_of_order 240s [test_abstract_jb.c:AST_JB_ADAPTIVE_put_out_of_order:521]: Executing AST_JB_ADAPTIVE_put_out_of_order... 240s END /main/abstract_jb/ - AST_JB_ADAPTIVE_put_out_of_order Time: <1ms Result: PASS 240s START /main/abstract_jb/ - AST_JB_ADAPTIVE_put_overflow 240s [test_abstract_jb.c:AST_JB_ADAPTIVE_put_overflow:519]: Executing AST_JB_ADAPTIVE_put_overflow... 240s END /main/abstract_jb/ - AST_JB_ADAPTIVE_put_overflow Time: <1ms Result: PASS 240s START /main/abstract_jb/ - AST_JB_ADAPTIVE_put 240s [test_abstract_jb.c:AST_JB_ADAPTIVE_put:517]: Executing AST_JB_ADAPTIVE_put... 240s END /main/abstract_jb/ - AST_JB_ADAPTIVE_put Time: <1ms Result: PASS 240s START /main/abstract_jb/ - AST_JB_ADAPTIVE_put_first 240s [test_abstract_jb.c:AST_JB_ADAPTIVE_put_first:515]: Executing AST_JB_ADAPTIVE_create... 240s END /main/abstract_jb/ - AST_JB_ADAPTIVE_put_first Time: <1ms Result: PASS 240s START /main/abstract_jb/ - AST_JB_ADAPTIVE_create 240s [test_abstract_jb.c:AST_JB_ADAPTIVE_create:513]: Executing AST_JB_ADAPTIVE_create... 240s END /main/abstract_jb/ - AST_JB_ADAPTIVE_create Time: <1ms Result: PASS 240s START /main/acl/ - acl 240s END /main/acl/ - acl Time: <1ms Result: PASS 240s START /main/acl/ - invalid_acl 240s END /main/acl/ - invalid_acl Time: <1ms Result: PASS 240s START /main/amihooks/ - amihook_cli_send 240s END /main/amihooks/ - amihook_cli_send Time: <1ms Result: PASS 240s START /main/aoc/ - aoc_event_test 240s END /main/aoc/ - aoc_event_test Time: <1ms Result: PASS 240s START /main/aoc/ - aoc_encode_decode_test 240s END /main/aoc/ - aoc_encode_decode_test Time: <1ms Result: PASS 240s START /main/app/ - options_parsing 240s END /main/app/ - options_parsing Time: <1ms Result: PASS 240s START /main/app/ - app_group 240s [test_app.c:app_group:172]: Creating test channels with the following groups: 240s 'a groupgroupgroup', 'a groupGroupgroup', 'a group@a_category', 'a group@another!Category' 240s [test_app.c:app_group:211]: (Subtest 1) Found 4 matches as expected when examining group:'gr' category:'' 240s [test_app.c:app_group:211]: (Subtest 2) Found 1 matches as expected when examining group:'(group){2}$' category:'' 240s [test_app.c:app_group:211]: (Subtest 3) Found 4 matches as expected when examining group:'[:ascii:]' category:'' 240s [test_app.c:app_group:211]: (Subtest 4) Found 0 matches as expected when examining group:'^(NOMATCH)' category:'' 240s [test_app.c:app_group:211]: (Subtest 5) Found 2 matches as expected when examining group:'a group' category:'(gory)$' 240s [test_app.c:app_group:211]: (Subtest 6) Found 1 matches as expected when examining group:'a group' category:'[A-Z]+' 240s [test_app.c:app_group:211]: (Subtest 7) Found 0 matches as expected when examining group:'a group' category:'[[' 240s END /main/app/ - app_group Time: <1ms Result: PASS 240s START /main/ast_expr/ - expr_test 240s END /main/ast_expr/ - expr_test Time: <1ms Result: PASS 240s START /main/astdb/ - put_get_long 240s END /main/astdb/ - put_get_long Time: 83ms Result: PASS 240s START /main/astdb/ - perftest 240s END /main/astdb/ - perftest Time: 426ms Result: PASS 240s START /main/astdb/ - gettree_deltree 240s END /main/astdb/ - gettree_deltree Time: <1ms Result: PASS 240s START /main/astdb/ - put_get_del 240s END /main/astdb/ - put_get_del Time: <1ms Result: PASS 240s START /main/astobj2/ - astobj2_weak_container 240s END /main/astobj2/ - astobj2_weak_container Time: <1ms Result: PASS 240s START /main/astobj2/ - astobj2_weak1 240s END /main/astobj2/ - astobj2_weak1 Time: <1ms Result: PASS 240s START /main/astobj2/ - astobj2_test4 240s [test_astobj2.c:test_traversal_nonsorted:1389]: Test 1, List containers. 240s [test_astobj2.c:test_traversal_nonsorted:1389]: Test 2, Hash containers. 240s [test_astobj2.c:test_traversal_sorted:1615]: Test 3, List containers. 240s [test_astobj2.c:test_traversal_sorted:1615]: Test 4, Hash containers. 240s [test_astobj2.c:test_traversal_sorted:1615]: Test 5, RBTree containers. 240s END /main/astobj2/ - astobj2_test4 Time: <1ms Result: PASS 240s START /main/astobj2/ - astobj2_test3 240s END /main/astobj2/ - astobj2_test3 Time: <1ms Result: PASS 240s START /main/astobj2/ - astobj2_test2 240s END /main/astobj2/ - astobj2_test2 Time: <1ms Result: PASS 240s START /main/astobj2/ - astobj2_test1 240s [test_astobj2.c:astobj2_test_1_helper:434]: Test 1, List containers (non-sorted). 240s [test_astobj2.c:astobj2_test_1_helper:488]: List container created: buckets: 1, items: 50 240s [test_astobj2.c:astobj2_test_1_helper:434]: Test 2, List containers (sorted). 240s [test_astobj2.c:astobj2_test_1_helper:488]: List container created: buckets: 1, items: 50 240s [test_astobj2.c:astobj2_test_1_helper:434]: Test 3, Hash containers (non-sorted). 240s [test_astobj2.c:astobj2_test_1_helper:488]: Hash container created: buckets: 73, items: 1000 240s [test_astobj2.c:astobj2_test_1_helper:434]: Test 4, Hash containers (sorted). 240s [test_astobj2.c:astobj2_test_1_helper:488]: Hash container created: buckets: 175, items: 1000 240s [test_astobj2.c:astobj2_test_1_helper:434]: Test 4, RBTree containers (sorted). 240s [test_astobj2.c:astobj2_test_1_helper:488]: RBTree container created: buckets: 1, items: 1000 240s END /main/astobj2/ - astobj2_test1 Time: 17ms Result: PASS 240s START /main/astobj2/ - thrash 240s [test_astobj2_thrash.c:hash_test:266]: Executing hash concurrency test... 240s END /main/astobj2/ - thrash Time: 19ms Result: PASS 240s START /main/astobj2/perf/ - astobj2_test_perf 242s [test_astobj2.c:testloop:2001]: 20.00K traversals, List 243s [test_astobj2.c:testloop:2001]: 40.00K traversals, List 245s [test_astobj2.c:testloop:2001]: 60.00K traversals, List 246s [test_astobj2.c:testloop:2001]: 80.00K traversals, List 247s [test_astobj2.c:testloop:2006]: 100.00K traversals, List : 6801 ms 248s [test_astobj2.c:testloop:2001]: 20.00K traversals, Hash 249s [test_astobj2.c:testloop:2001]: 40.00K traversals, Hash 250s [test_astobj2.c:testloop:2001]: 60.00K traversals, Hash 251s [test_astobj2.c:testloop:2001]: 80.00K traversals, Hash 252s [test_astobj2.c:testloop:2006]: 100.00K traversals, Hash : 4776 ms 253s [test_astobj2.c:testloop:2001]: 20.00K traversals, RBTree 254s [test_astobj2.c:testloop:2001]: 40.00K traversals, RBTree 255s [test_astobj2.c:testloop:2001]: 60.00K traversals, RBTree 256s [test_astobj2.c:testloop:2001]: 80.00K traversals, RBTree 257s [test_astobj2.c:testloop:2006]: 100.00K traversals, RBTree : 5357 ms 257s END /main/astobj2/perf/ - astobj2_test_perf Time: 16937ms Result: PASS 257s START /main/bridging/ - test_bridging_deferred_queue 258s END /main/bridging/ - test_bridging_deferred_queue Time: 1014ms Result: PASS 258s START /main/bucket/ - bucket_file_json 258s [test_bucket.c:bucket_file_json:956]: Failed to allocate bucket 258s END /main/bucket/ - bucket_file_json Time: <1ms Result: FAIL 258s START /main/bucket/ - bucket_file_metadata_get 258s [test_bucket.c:bucket_file_metadata_get:914]: Failed to allocate file 258s END /main/bucket/ - bucket_file_metadata_get Time: <1ms Result: FAIL 258s START /main/bucket/ - bucket_file_metadata_unset 258s [test_bucket.c:bucket_file_metadata_unset:874]: Failed to allocate file 258s END /main/bucket/ - bucket_file_metadata_unset Time: <1ms Result: FAIL 258s START /main/bucket/ - bucket_file_metadata_set 258s [test_bucket.c:bucket_file_metadata_set:808]: Failed to allocate file 258s END /main/bucket/ - bucket_file_metadata_set Time: <1ms Result: FAIL 258s START /main/bucket/ - bucket_file_is_stale 258s [test_bucket.c:bucket_file_is_stale:775]: Failed to allocate file 258s END /main/bucket/ - bucket_file_is_stale Time: <1ms Result: FAIL 258s START /main/bucket/ - bucket_file_delete 258s [test_bucket.c:bucket_file_delete:732]: Failed to allocate file 258s END /main/bucket/ - bucket_file_delete Time: <1ms Result: FAIL 258s START /main/bucket/ - bucket_file_update 258s [test_bucket.c:bucket_file_update:689]: Failed to allocate file 258s END /main/bucket/ - bucket_file_update Time: <1ms Result: FAIL 258s START /main/bucket/ - bucket_file_retrieve 258s [test_bucket.c:bucket_file_retrieve:665]: Failed to retrieve known valid file 258s END /main/bucket/ - bucket_file_retrieve Time: <1ms Result: FAIL 258s START /main/bucket/ - bucket_file_copy 258s [test_bucket.c:bucket_file_copy:594]: Failed to allocate file 258s END /main/bucket/ - bucket_file_copy Time: <1ms Result: FAIL 258s START /main/bucket/ - bucket_file_clone 258s [test_bucket.c:bucket_file_clone:545]: Failed to allocate file 258s END /main/bucket/ - bucket_file_clone Time: <1ms Result: FAIL 258s START /main/bucket/ - bucket_file_create 258s [test_bucket.c:bucket_file_create:501]: Failed to allocate file 258s END /main/bucket/ - bucket_file_create Time: <1ms Result: FAIL 258s START /main/bucket/ - bucket_file_alloc 258s [test_bucket.c:bucket_file_alloc:460]: Failed to allocate file 258s END /main/bucket/ - bucket_file_alloc Time: <1ms Result: FAIL 258s START /main/bucket/ - bucket_json 258s END /main/bucket/ - bucket_json Time: <1ms Result: PASS 258s START /main/bucket/ - bucket_is_stale 258s END /main/bucket/ - bucket_is_stale Time: <1ms Result: PASS 258s START /main/bucket/ - bucket_retrieve 258s END /main/bucket/ - bucket_retrieve Time: <1ms Result: PASS 258s START /main/bucket/ - bucket_delete 258s END /main/bucket/ - bucket_delete Time: <1ms Result: PASS 258s START /main/bucket/ - bucket_clone 258s END /main/bucket/ - bucket_clone Time: <1ms Result: PASS 258s START /main/bucket/ - bucket_create 258s END /main/bucket/ - bucket_create Time: <1ms Result: PASS 258s START /main/bucket/ - bucket_alloc 258s END /main/bucket/ - bucket_alloc Time: <1ms Result: PASS 258s START /main/bucket/ - bucket_scheme_register_unregister 258s END /main/bucket/ - bucket_scheme_register_unregister Time: <1ms Result: PASS 258s START /main/callerid/ - parse_off_nominal 258s END /main/callerid/ - parse_off_nominal Time: <1ms Result: PASS 258s START /main/callerid/ - parse_nominal 258s END /main/callerid/ - parse_nominal Time: <1ms Result: PASS 258s START /main/cdr/ - test_cdr_fork_cdr 260s Verifying expected record CDRTestChannel/Alice, 260s Finished expected record CDRTestChannel/Alice, 260s Verifying expected record CDRTestChannel/Alice, 260s Finished expected record CDRTestChannel/Alice, 260s Verifying expected record CDRTestChannel/Alice, 260s Finished expected record CDRTestChannel/Alice, 260s END /main/cdr/ - test_cdr_fork_cdr Time: 2003ms Result: PASS 260s START /main/cdr/ - test_cdr_no_reset_cdr 261s Verifying expected record CDRTestChannel/Alice, 261s Finished expected record CDRTestChannel/Alice, 261s END /main/cdr/ - test_cdr_no_reset_cdr Time: 1001ms Result: PASS 261s START /main/cdr/ - test_cdr_fields 263s Verifying expected record CDRTestChannel/Alice, 263s Finished expected record CDRTestChannel/Alice, 263s Verifying expected record CDRTestChannel/Alice, 263s Finished expected record CDRTestChannel/Alice, 263s Verifying expected record CDRTestChannel/Alice, 263s Finished expected record CDRTestChannel/Alice, 263s END /main/cdr/ - test_cdr_fields Time: 2001ms Result: PASS 263s START /main/cdr/ - test_cdr_park 266s Verifying expected record CDRTestChannel/Alice, 266s Finished expected record CDRTestChannel/Alice, 266s Verifying expected record CDRTestChannel/Bob, 266s Finished expected record CDRTestChannel/Bob, 266s END /main/cdr/ - test_cdr_park Time: 3001ms Result: PASS 266s START /main/cdr/ - test_cdr_dial_answer_multiparty 271s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 271s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 271s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Charlie 271s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Charlie 271s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/David 271s Finished expected record CDRTestChannel/Alice, CDRTestChannel/David 271s Verifying expected record CDRTestChannel/Bob, CDRTestChannel/David 271s Finished expected record CDRTestChannel/Bob, CDRTestChannel/David 271s Verifying expected record CDRTestChannel/Charlie, CDRTestChannel/David 271s Finished expected record CDRTestChannel/Charlie, CDRTestChannel/David 271s Verifying expected record CDRTestChannel/Charlie, CDRTestChannel/Bob 271s Finished expected record CDRTestChannel/Charlie, CDRTestChannel/Bob 271s END /main/cdr/ - test_cdr_dial_answer_multiparty Time: 5005ms Result: PASS 271s START /main/cdr/ - test_cdr_dial_answer_twoparty_bridge_b 274s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 274s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 274s END /main/cdr/ - test_cdr_dial_answer_twoparty_bridge_b Time: 3002ms Result: PASS 274s START /main/cdr/ - test_cdr_dial_answer_twoparty_bridge_a 276s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 276s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 276s END /main/cdr/ - test_cdr_dial_answer_twoparty_bridge_a Time: 2001ms Result: PASS 276s START /main/cdr/ - test_cdr_dial_answer_no_bridge 276s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 276s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 276s Verifying expected record CDRTestChannel/Alice, 276s Finished expected record CDRTestChannel/Alice, 276s Verifying expected record CDRTestChannel/Bob, 276s Finished expected record CDRTestChannel/Bob, 276s END /main/cdr/ - test_cdr_dial_answer_no_bridge Time: 1ms Result: PASS 276s START /main/cdr/ - test_cdr_dial_parallel_failed 276s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 276s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 276s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Charlie 276s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Charlie 276s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/David 276s Finished expected record CDRTestChannel/Alice, CDRTestChannel/David 276s END /main/cdr/ - test_cdr_dial_parallel_failed Time: 1ms Result: PASS 276s START /main/cdr/ - test_cdr_dial_caller_cancel 276s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 276s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 276s END /main/cdr/ - test_cdr_dial_caller_cancel Time: <1ms Result: PASS 276s START /main/cdr/ - test_cdr_dial_unavailable 276s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 276s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 276s END /main/cdr/ - test_cdr_dial_unavailable Time: <1ms Result: PASS 276s START /main/cdr/ - test_cdr_dial_busy 276s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 276s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 276s END /main/cdr/ - test_cdr_dial_busy Time: <1ms Result: PASS 276s START /main/cdr/ - test_cdr_dial_congestion 276s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 276s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 276s END /main/cdr/ - test_cdr_dial_congestion Time: <1ms Result: PASS 276s START /main/cdr/ - test_cdr_dial_unanswered 276s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 276s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 276s END /main/cdr/ - test_cdr_dial_unanswered Time: <1ms Result: PASS 276s START /main/cdr/ - test_cdr_outbound_bridged_call 279s Verifying expected record CDRTestChannel/Bob, 279s Finished expected record CDRTestChannel/Bob, 279s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 279s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 279s END /main/cdr/ - test_cdr_outbound_bridged_call Time: 3001ms Result: PASS 279s START /main/cdr/ - test_cdr_single_multiparty_bridge 283s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 283s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 283s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Charlie 283s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Charlie 283s Verifying expected record CDRTestChannel/Bob, CDRTestChannel/Charlie 283s Finished expected record CDRTestChannel/Bob, CDRTestChannel/Charlie 283s Verifying expected record CDRTestChannel/Charlie, 283s Finished expected record CDRTestChannel/Charlie, 283s END /main/cdr/ - test_cdr_single_multiparty_bridge Time: 4002ms Result: PASS 283s START /main/cdr/ - test_cdr_single_twoparty_bridge_b 286s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 286s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 286s Verifying expected record CDRTestChannel/Bob, 286s Finished expected record CDRTestChannel/Bob, 286s END /main/cdr/ - test_cdr_single_twoparty_bridge_b Time: 3001ms Result: PASS 286s START /main/cdr/ - test_cdr_single_twoparty_bridge_a 288s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 288s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 288s Verifying expected record CDRTestChannel/Bob, 288s Finished expected record CDRTestChannel/Bob, 288s END /main/cdr/ - test_cdr_single_twoparty_bridge_a Time: 2001ms Result: PASS 288s START /main/cdr/ - test_cdr_single_bridge_continue 290s Verifying expected record CDRTestChannel/Alice, 290s Finished expected record CDRTestChannel/Alice, 290s Verifying expected record CDRTestChannel/Alice, 290s Finished expected record CDRTestChannel/Alice, 290s END /main/cdr/ - test_cdr_single_bridge_continue Time: 2001ms Result: PASS 290s START /main/cdr/ - test_cdr_single_bridge 292s Verifying expected record CDRTestChannel/Alice, 292s Finished expected record CDRTestChannel/Alice, 292s END /main/cdr/ - test_cdr_single_bridge Time: 2000ms Result: PASS 292s START /main/cdr/ - test_cdr_single_party 292s Verifying expected record CDRTestChannel/Alice, 292s Finished expected record CDRTestChannel/Alice, 292s END /main/cdr/ - test_cdr_single_party Time: <1ms Result: PASS 292s START /main/cdr/ - test_cdr_unanswered_outbound_call 292s Verifying expected record CDRTestChannel/Alice, 292s Finished expected record CDRTestChannel/Alice, 292s END /main/cdr/ - test_cdr_unanswered_outbound_call Time: <1ms Result: PASS 292s START /main/cdr/ - test_cdr_unanswered_inbound_call 292s Verifying expected record CDRTestChannel/Alice, 292s Finished expected record CDRTestChannel/Alice, 292s END /main/cdr/ - test_cdr_unanswered_inbound_call Time: <1ms Result: PASS 292s START /main/cdr/ - test_cdr_channel_creation 292s Verifying expected record CDRTestChannel/Alice, 292s Finished expected record CDRTestChannel/Alice, 292s END /main/cdr/ - test_cdr_channel_creation Time: <1ms Result: PASS 292s START /main/channel/ - add_fd 292s END /main/channel/ - add_fd Time: <1ms Result: PASS 292s START /main/channel/ - set_fd_grow 292s END /main/channel/ - set_fd_grow Time: <1ms Result: PASS 292s START /main/config/ - variable_list_from_quoted_string 292s END /main/config/ - variable_list_from_quoted_string Time: <1ms Result: PASS 292s START /main/config/ - variable_list_join_replace 292s END /main/config/ - variable_list_join_replace Time: <1ms Result: PASS 292s START /main/config/ - variable_lists_match 292s END /main/config/ - variable_lists_match Time: <1ms Result: PASS 292s START /main/config/ - config_dialplan_function 292s END /main/config/ - config_dialplan_function Time: <1ms Result: PASS 292s START /main/config/ - config_hook 292s END /main/config/ - config_hook Time: <1ms Result: PASS 292s START /main/config/ - copy_config 292s END /main/config/ - copy_config Time: <1ms Result: PASS 292s START /main/config/ - config_template_ops 292s END /main/config/ - config_template_ops Time: <1ms Result: PASS 292s START /main/config/ - config_filtered_ops 292s END /main/config/ - config_filtered_ops Time: <1ms Result: PASS 292s START /main/config/ - config_basic_ops 292s END /main/config/ - config_basic_ops Time: <1ms Result: PASS 292s START /main/config/ - config_save 292s END /main/config/ - config_save Time: <1ms Result: PASS 292s START /main/conversions/ - str_to_umax 292s END /main/conversions/ - str_to_umax Time: <1ms Result: PASS 292s START /main/conversions/ - str_to_imax 292s END /main/conversions/ - str_to_imax Time: <1ms Result: PASS 292s START /main/conversions/ - str_to_ulong 292s END /main/conversions/ - str_to_ulong Time: <1ms Result: PASS 292s START /main/conversions/ - str_to_long 292s END /main/conversions/ - str_to_long Time: <1ms Result: PASS 292s START /main/conversions/ - str_to_uint 292s END /main/conversions/ - str_to_uint Time: <1ms Result: PASS 292s START /main/conversions/ - str_to_int 292s END /main/conversions/ - str_to_int Time: <1ms Result: PASS 292s START /main/core_codec/ - codec_get_unknown 292s END /main/core_codec/ - codec_get_unknown Time: <1ms Result: PASS 292s START /main/core_codec/ - codec_get_unknown 292s END /main/core_codec/ - codec_get_unknown Time: <1ms Result: PASS 292s START /main/core_codec/ - codec_get_unregistered 292s END /main/core_codec/ - codec_get_unregistered Time: <1ms Result: PASS 292s START /main/core_codec/ - codec_get 292s END /main/core_codec/ - codec_get Time: <1ms Result: PASS 292s START /main/core_codec/ - codec_register_audio_no_sample_rate 292s END /main/core_codec/ - codec_register_audio_no_sample_rate Time: <1ms Result: PASS 292s START /main/core_codec/ - codec_register_unknown 292s END /main/core_codec/ - codec_register_unknown Time: <1ms Result: PASS 292s START /main/core_codec/ - codec_register_twice 292s END /main/core_codec/ - codec_register_twice Time: <1ms Result: PASS 292s START /main/core_codec/ - codec_register 292s END /main/core_codec/ - codec_register Time: <1ms Result: PASS 292s START /main/core_format/ - format_parse_and_generate_sdp_fmtp 292s END /main/core_format/ - format_parse_and_generate_sdp_fmtp Time: <1ms Result: PASS 292s START /main/core_format/ - format_parse_sdp_fmtp_without_interface 292s END /main/core_format/ - format_parse_sdp_fmtp_without_interface Time: <1ms Result: PASS 292s START /main/core_format/ - format_attribute_get_without_interface 292s END /main/core_format/ - format_attribute_get_without_interface Time: <1ms Result: PASS 292s START /main/core_format/ - format_attribute_set_without_interface 292s END /main/core_format/ - format_attribute_set_without_interface Time: <1ms Result: PASS 292s START /main/core_format/ - format_copy 292s END /main/core_format/ - format_copy Time: <1ms Result: PASS 292s START /main/core_format/ - format_joint_different_codec 292s END /main/core_format/ - format_joint_different_codec Time: <1ms Result: PASS 292s START /main/core_format/ - format_attr_joint_same_codec 292s END /main/core_format/ - format_attr_joint_same_codec Time: <1ms Result: PASS 292s START /main/core_format/ - format_joint_same_codec 292s END /main/core_format/ - format_joint_same_codec Time: <1ms Result: PASS 292s START /main/core_format/ - format_cmp_different_codec 292s END /main/core_format/ - format_cmp_different_codec Time: <1ms Result: PASS 292s START /main/core_format/ - format_attr_cmp_same_codec 292s END /main/core_format/ - format_attr_cmp_same_codec Time: <1ms Result: PASS 292s START /main/core_format/ - format_cmp_same_codec 292s END /main/core_format/ - format_cmp_same_codec Time: <1ms Result: PASS 292s START /main/core_format/ - format_clone 292s END /main/core_format/ - format_clone Time: <1ms Result: PASS 292s START /main/core_format/ - format_retrieve_attr 292s END /main/core_format/ - format_retrieve_attr Time: <1ms Result: PASS 292s START /main/core_format/ - format_create_attr 292s END /main/core_format/ - format_create_attr Time: <1ms Result: PASS 292s START /main/core_format/ - format_create 292s END /main/core_format/ - format_create Time: <1ms Result: PASS 292s START /main/data_buffer/ - buffer_nominal 292s END /main/data_buffer/ - buffer_nominal Time: <1ms Result: PASS 292s START /main/data_buffer/ - buffer_resize 292s END /main/data_buffer/ - buffer_resize Time: <1ms Result: PASS 292s START /main/data_buffer/ - buffer_put 292s END /main/data_buffer/ - buffer_put Time: <1ms Result: PASS 292s START /main/data_buffer/ - buffer_create 292s END /main/data_buffer/ - buffer_create Time: <1ms Result: PASS 292s START /main/devicestate/ - devstate_channels 292s END /main/devicestate/ - devstate_channels Time: <1ms Result: PASS 292s START /main/devicestate/ - devstate_conversions 292s END /main/devicestate/ - devstate_conversions Time: <1ms Result: PASS 292s START /main/devicestate/ - devstate_changed 292s [test_devicestate.c:wait_for_device_state_updates:308]: Received 8 of 8 updates 292s [test_devicestate.c:devstate_changed:716]: Testing update 0: actual is 1; expected is 1 292s [test_devicestate.c:devstate_changed:716]: Testing update 1: actual is 2; expected is 2 292s [test_devicestate.c:devstate_changed:716]: Testing update 2: actual is 3; expected is 3 292s [test_devicestate.c:devstate_changed:716]: Testing update 3: actual is 4; expected is 4 292s [test_devicestate.c:devstate_changed:716]: Testing update 4: actual is 5; expected is 5 292s [test_devicestate.c:devstate_changed:716]: Testing update 5: actual is 6; expected is 6 292s [test_devicestate.c:devstate_changed:716]: Testing update 6: actual is 7; expected is 7 292s [test_devicestate.c:devstate_changed:716]: Testing update 7: actual is 8; expected is 8 292s [test_devicestate.c:wait_for_device_state_updates:308]: Received 1 of 1 updates 292s [test_devicestate.c:wait_for_device_state_updates:308]: Received 8 of 8 updates 292s [test_devicestate.c:devstate_changed:754]: Testing update 0: actual is 1; expected is 1 292s [test_devicestate.c:devstate_changed:754]: Testing update 1: actual is 2; expected is 2 292s [test_devicestate.c:devstate_changed:754]: Testing update 2: actual is 3; expected is 3 292s [test_devicestate.c:devstate_changed:754]: Testing update 3: actual is 4; expected is 4 292s [test_devicestate.c:devstate_changed:754]: Testing update 4: actual is 5; expected is 5 292s [test_devicestate.c:devstate_changed:754]: Testing update 5: actual is 6; expected is 6 292s [test_devicestate.c:devstate_changed:754]: Testing update 6: actual is 7; expected is 7 292s [test_devicestate.c:devstate_changed:754]: Testing update 7: actual is 8; expected is 8 292s END /main/devicestate/ - devstate_changed Time: 1ms Result: PASS 292s START /main/devicestate/ - devstate_prov_del 292s END /main/devicestate/ - devstate_prov_del Time: <1ms Result: PASS 292s START /main/devicestate/ - devstate_prov_add 292s END /main/devicestate/ - devstate_prov_add Time: <1ms Result: PASS 292s START /main/devicestate/ - device2extenstate_test 292s END /main/devicestate/ - device2extenstate_test Time: <1ms Result: PASS 292s START /main/devicestate/ - device_state_aggregation_test 292s END /main/devicestate/ - device_state_aggregation_test Time: <1ms Result: PASS 292s START /main/dns/ - resolver_resolve_async_cancel 292s END /main/dns/ - resolver_resolve_async_cancel Time: <1ms Result: PASS 292s START /main/dns/ - resolver_resolve_async_off_nominal 292s END /main/dns/ - resolver_resolve_async_off_nominal Time: <1ms Result: PASS 292s START /main/dns/ - resolver_resolve_async 297s END /main/dns/ - resolver_resolve_async Time: 5000ms Result: PASS 297s START /main/dns/ - resolver_resolve_sync_off_nominal 297s END /main/dns/ - resolver_resolve_sync_off_nominal Time: <1ms Result: PASS 297s START /main/dns/ - resolver_resolve_sync 302s END /main/dns/ - resolver_resolve_sync Time: 5000ms Result: PASS 302s START /main/dns/ - resolver_add_record_off_nominal 302s END /main/dns/ - resolver_add_record_off_nominal Time: <1ms Result: PASS 302s START /main/dns/ - resolver_add_record 302s END /main/dns/ - resolver_add_record Time: <1ms Result: PASS 302s START /main/dns/ - resolver_set_result_off_nominal 302s END /main/dns/ - resolver_set_result_off_nominal Time: <1ms Result: PASS 302s START /main/dns/ - resolver_set_result 302s END /main/dns/ - resolver_set_result Time: <1ms Result: PASS 302s START /main/dns/ - resolver_data 302s END /main/dns/ - resolver_data Time: <1ms Result: PASS 302s START /main/dns/ - resolver_unregister_off_nominal 302s END /main/dns/ - resolver_unregister_off_nominal Time: <1ms Result: PASS 302s START /main/dns/ - resolver_register_off_nominal 302s END /main/dns/ - resolver_register_off_nominal Time: <1ms Result: PASS 302s START /main/dns/ - resolver_register_unregister 302s END /main/dns/ - resolver_register_unregister Time: <1ms Result: PASS 302s START /main/dns/naptr/ - naptr_resolve_off_nominal_interactions 302s END /main/dns/naptr/ - naptr_resolve_off_nominal_interactions Time: <1ms Result: PASS 302s START /main/dns/naptr/ - naptr_resolve_off_nominal_regexp 302s END /main/dns/naptr/ - naptr_resolve_off_nominal_regexp Time: <1ms Result: PASS 302s START /main/dns/naptr/ - naptr_resolve_off_nominal_services 302s END /main/dns/naptr/ - naptr_resolve_off_nominal_services Time: <1ms Result: PASS 302s START /main/dns/naptr/ - naptr_resolve_off_nominal_flags 302s END /main/dns/naptr/ - naptr_resolve_off_nominal_flags Time: <1ms Result: PASS 302s START /main/dns/naptr/ - naptr_resolve_off_nominal_length 302s END /main/dns/naptr/ - naptr_resolve_off_nominal_length Time: <1ms Result: PASS 302s START /main/dns/naptr/ - naptr_resolve 302s END /main/dns/naptr/ - naptr_resolve Time: <1ms Result: PASS 302s START /main/dns/query_set/ - query_set_off_nominal_cancel 302s END /main/dns/query_set/ - query_set_off_nominal_cancel Time: <1ms Result: PASS 302s START /main/dns/query_set/ - query_set_nominal_cancel 302s END /main/dns/query_set/ - query_set_nominal_cancel Time: <1ms Result: PASS 302s START /main/dns/query_set/ - query_set_empty 302s END /main/dns/query_set/ - query_set_empty Time: <1ms Result: PASS 302s START /main/dns/query_set/ - query_set 302s END /main/dns/query_set/ - query_set Time: <1ms Result: PASS 302s START /main/dns/recurring/ - recurring_query_cancel_during 302s [test_dns_recurring.c:wait_for_resolution:252]: Query completed in expected time frame 309s [test_dns_recurring.c:wait_for_resolution:252]: Query completed in expected time frame 319s END /main/dns/recurring/ - recurring_query_cancel_during Time: 16999ms Result: PASS 319s START /main/dns/recurring/ - recurring_query_cancel_between 319s [test_dns_recurring.c:wait_for_resolution:252]: Query completed in expected time frame 329s END /main/dns/recurring/ - recurring_query_cancel_between Time: 10001ms Result: PASS 329s START /main/dns/recurring/ - recurring_query_off_nominal 329s END /main/dns/recurring/ - recurring_query_off_nominal Time: <1ms Result: PASS 329s START /main/dns/recurring/ - recurring_query 329s [test_dns_recurring.c:wait_for_resolution:252]: Query completed in expected time frame 336s [test_dns_recurring.c:wait_for_resolution:252]: Query completed in expected time frame 348s [test_dns_recurring.c:wait_for_resolution:252]: Query completed in expected time frame 348s END /main/dns/recurring/ - recurring_query Time: 19002ms Result: PASS 348s START /main/dns/srv/ - srv_resolve_record_missing_host 348s END /main/dns/srv/ - srv_resolve_record_missing_host Time: <1ms Result: PASS 348s START /main/dns/srv/ - srv_resolve_record_missing_port_host 348s END /main/dns/srv/ - srv_resolve_record_missing_port_host Time: <1ms Result: PASS 348s START /main/dns/srv/ - srv_resolve_record_missing_weight_port_host 348s END /main/dns/srv/ - srv_resolve_record_missing_weight_port_host Time: <1ms Result: PASS 348s START /main/dns/srv/ - srv_resolve_different_priorities_different_weights 348s END /main/dns/srv/ - srv_resolve_different_priorities_different_weights Time: 4ms Result: PASS 348s START /main/dns/srv/ - srv_resolve_same_priority_different_weights 348s END /main/dns/srv/ - srv_resolve_same_priority_different_weights Time: 3ms Result: PASS 348s START /main/dns/srv/ - srv_resolve_same_priority_zero_weight 348s END /main/dns/srv/ - srv_resolve_same_priority_zero_weight Time: <1ms Result: PASS 348s START /main/dns/srv/ - srv_resolve_sort_priority 348s END /main/dns/srv/ - srv_resolve_sort_priority Time: <1ms Result: PASS 348s START /main/dns/srv/ - srv_resolve_single_record 348s END /main/dns/srv/ - srv_resolve_single_record Time: <1ms Result: PASS 348s START /main/dsp/ - dtmf 348s END /main/dsp/ - dtmf Time: 5ms Result: PASS 348s START /main/dsp/ - fax 349s END /main/dsp/ - fax Time: 784ms Result: PASS 349s START /main/event/ - ast_event_new_test 349s [test_event.c:event_new_test:125]: First, test dynamic event creation... 349s [test_event.c:check_event:88]: Event looks good. 349s [test_event.c:check_event:88]: Event looks good. 349s END /main/event/ - ast_event_new_test Time: <1ms Result: PASS 349s START /main/file/ - read_dir_test 349s END /main/file/ - read_dir_test Time: <1ms Result: PASS 349s START /main/file/ - ast_format_str_reduce_test_1 349s END /main/file/ - ast_format_str_reduce_test_1 Time: <1ms Result: PASS 349s START /main/format_cache/ - format_cache_get_nonxistent 349s END /main/format_cache/ - format_cache_get_nonxistent Time: <1ms Result: PASS 349s START /main/format_cache/ - format_cache_get 349s END /main/format_cache/ - format_cache_get Time: <1ms Result: PASS 349s START /main/format_cache/ - format_cache_set_null 349s END /main/format_cache/ - format_cache_set_null Time: <1ms Result: PASS 349s START /main/format_cache/ - format_cache_set_duplicate 349s END /main/format_cache/ - format_cache_set_duplicate Time: <1ms Result: PASS 349s START /main/format_cache/ - format_cache_set 349s END /main/format_cache/ - format_cache_set Time: <1ms Result: PASS 349s START /main/format_cap/ - format_cap_replace_from_cap 349s END /main/format_cap/ - format_cap_replace_from_cap Time: <1ms Result: PASS 349s START /main/format_cap/ - format_cap_best_by_type 349s END /main/format_cap/ - format_cap_best_by_type Time: <1ms Result: PASS 349s START /main/format_cap/ - format_cap_iscompatible 349s END /main/format_cap/ - format_cap_iscompatible Time: <1ms Result: PASS 349s START /main/format_cap/ - format_cap_get_compatible 349s END /main/format_cap/ - format_cap_get_compatible Time: <1ms Result: PASS 349s START /main/format_cap/ - format_cap_iscompatible_format 349s END /main/format_cap/ - format_cap_iscompatible_format Time: <1ms Result: PASS 349s START /main/format_cap/ - format_cap_get_compatible_format 349s END /main/format_cap/ - format_cap_get_compatible_format Time: <1ms Result: PASS 349s START /main/format_cap/ - format_cap_get_names 349s END /main/format_cap/ - format_cap_get_names Time: <1ms Result: PASS 349s START /main/format_cap/ - format_cap_remove_all 349s END /main/format_cap/ - format_cap_remove_all Time: <1ms Result: PASS 349s START /main/format_cap/ - format_cap_remove_bytype 349s END /main/format_cap/ - format_cap_remove_bytype Time: <1ms Result: PASS 349s START /main/format_cap/ - format_cap_remove_multiple 349s END /main/format_cap/ - format_cap_remove_multiple Time: <1ms Result: PASS 349s START /main/format_cap/ - format_cap_remove_single 349s END /main/format_cap/ - format_cap_remove_single Time: <1ms Result: PASS 349s START /main/format_cap/ - format_cap_set_framing 349s END /main/format_cap/ - format_cap_set_framing Time: <1ms Result: PASS 349s START /main/format_cap/ - format_cap_append_from_cap_duplicate 349s END /main/format_cap/ - format_cap_append_from_cap_duplicate Time: <1ms Result: PASS 349s START /main/format_cap/ - format_cap_append_from_cap 349s END /main/format_cap/ - format_cap_append_from_cap Time: <1ms Result: PASS 349s START /main/format_cap/ - format_cap_append_duplicate 349s END /main/format_cap/ - format_cap_append_duplicate Time: <1ms Result: PASS 349s START /main/format_cap/ - format_cap_append_all_audio 349s END /main/format_cap/ - format_cap_append_all_audio Time: <1ms Result: PASS 349s START /main/format_cap/ - format_cap_append_all_unknown 349s END /main/format_cap/ - format_cap_append_all_unknown Time: <1ms Result: PASS 349s START /main/format_cap/ - format_cap_append_multiple 349s END /main/format_cap/ - format_cap_append_multiple Time: <1ms Result: PASS 349s START /main/format_cap/ - format_cap_append_single 349s END /main/format_cap/ - format_cap_append_single Time: <1ms Result: PASS 349s START /main/format_cap/ - format_cap_alloc 349s END /main/format_cap/ - format_cap_alloc Time: <1ms Result: PASS 349s START /main/hashtab/ - thrash 349s [test_hashtab_thrash.c:hash_test:246]: Executing hash concurrency test... 349s END /main/hashtab/ - thrash Time: 20ms Result: PASS 349s START /main/heap/ - heap_test_3 349s END /main/heap/ - heap_test_3 Time: 132ms Result: PASS 349s START /main/heap/ - heap_test_2 349s END /main/heap/ - heap_test_2 Time: 118ms Result: PASS 349s START /main/heap/ - heap_test_1 349s END /main/heap/ - heap_test_1 Time: <1ms Result: PASS 349s START /main/jitterbuf/ - jitterbuffer_resynch_control 349s END /main/jitterbuf/ - jitterbuffer_resynch_control Time: <1ms Result: PASS 349s START /main/jitterbuf/ - jitterbuffer_resynch_voice 349s END /main/jitterbuf/ - jitterbuffer_resynch_voice Time: <1ms Result: PASS 349s START /main/jitterbuf/ - jitterbuffer_overflow_control 349s END /main/jitterbuf/ - jitterbuffer_overflow_control Time: <1ms Result: PASS 349s START /main/jitterbuf/ - jitterbuffer_overflow_voice 349s END /main/jitterbuf/ - jitterbuffer_overflow_voice Time: <1ms Result: PASS 349s START /main/jitterbuf/ - jitterbuffer_late_control 349s END /main/jitterbuf/ - jitterbuffer_late_control Time: <1ms Result: PASS 349s START /main/jitterbuf/ - jitterbuffer_late_voice 349s END /main/jitterbuf/ - jitterbuffer_late_voice Time: <1ms Result: PASS 349s START /main/jitterbuf/ - jitterbuffer_lost_control 349s END /main/jitterbuf/ - jitterbuffer_lost_control Time: <1ms Result: PASS 349s START /main/jitterbuf/ - jitterbuffer_lost_voice 349s END /main/jitterbuf/ - jitterbuffer_lost_voice Time: <1ms Result: PASS 349s START /main/jitterbuf/ - jitterbuffer_out_of_order_voice 349s END /main/jitterbuf/ - jitterbuffer_out_of_order_voice Time: <1ms Result: PASS 349s START /main/jitterbuf/ - jitterbuffer_out_of_order_voice 349s END /main/jitterbuf/ - jitterbuffer_out_of_order_voice Time: <1ms Result: PASS 349s START /main/jitterbuf/ - jitterbuffer_nominal_control_frames 349s END /main/jitterbuf/ - jitterbuffer_nominal_control_frames Time: <1ms Result: PASS 349s START /main/jitterbuf/ - jitterbuffer_nominal_voice_frames 349s END /main/jitterbuf/ - jitterbuffer_nominal_voice_frames Time: <1ms Result: PASS 349s START /main/json/ - cep 349s END /main/json/ - cep Time: <1ms Result: PASS 349s START /main/json/ - type_timeval 349s END /main/json/ - type_timeval Time: <1ms Result: PASS 349s START /main/json/ - name_number 349s END /main/json/ - name_number Time: <1ms Result: PASS 349s START /main/json/ - clever_circle 349s END /main/json/ - clever_circle Time: <1ms Result: PASS 349s START /main/json/ - circular_array 349s END /main/json/ - circular_array Time: <1ms Result: PASS 349s START /main/json/ - circular_object 349s END /main/json/ - circular_object Time: <1ms Result: PASS 349s START /main/json/ - copy_null 349s END /main/json/ - copy_null Time: <1ms Result: PASS 349s START /main/json/ - deep_copy 349s END /main/json/ - deep_copy Time: <1ms Result: PASS 349s START /main/json/ - copy 349s END /main/json/ - copy Time: <1ms Result: PASS 349s START /main/json/ - object_alloc 349s END /main/json/ - object_alloc Time: 1ms Result: PASS 349s START /main/json/ - pack_ownership 349s END /main/json/ - pack_ownership Time: <1ms Result: PASS 349s START /main/json/ - pack 349s END /main/json/ - pack Time: <1ms Result: PASS 349s START /main/json/ - parse_errors 349s END /main/json/ - parse_errors Time: <1ms Result: PASS 349s START /main/json/ - dump_load_null 349s END /main/json/ - dump_load_null Time: <1ms Result: PASS 349s START /main/json/ - dump_load_new_file 350s END /main/json/ - dump_load_new_file Time: <1ms Result: PASS 350s START /main/json/ - dump_load_file 350s END /main/json/ - dump_load_file Time: <1ms Result: PASS 350s START /main/json/ - load_buffer 350s END /main/json/ - load_buffer Time: <1ms Result: PASS 350s START /main/json/ - dump_str_fail 350s END /main/json/ - dump_str_fail Time: <1ms Result: PASS 350s START /main/json/ - dump_load_str 350s END /main/json/ - dump_load_str Time: <1ms Result: PASS 350s START /main/json/ - dump_load_string 350s END /main/json/ - dump_load_string Time: <1ms Result: PASS 350s START /main/json/ - object_create_vars 350s END /main/json/ - object_create_vars Time: <1ms Result: PASS 350s START /main/json/ - object_iter_null 350s END /main/json/ - object_iter_null Time: <1ms Result: PASS 350s START /main/json/ - object_iter 350s END /main/json/ - object_iter Time: <1ms Result: PASS 350s START /main/json/ - object_null 350s END /main/json/ - object_null Time: <1ms Result: PASS 350s START /main/json/ - object_merge_missing 350s END /main/json/ - object_merge_missing Time: <1ms Result: PASS 350s START /main/json/ - object_alloc 350s END /main/json/ - object_alloc Time: <1ms Result: PASS 350s START /main/json/ - object_alloc 350s END /main/json/ - object_alloc Time: <1ms Result: PASS 350s START /main/json/ - object_clear 350s END /main/json/ - object_clear Time: <1ms Result: PASS 350s START /main/json/ - object_del 350s END /main/json/ - object_del Time: <1ms Result: PASS 350s START /main/json/ - object_get 350s END /main/json/ - object_get Time: <1ms Result: PASS 350s START /main/json/ - object_set_overwriting 350s END /main/json/ - object_set_overwriting Time: <1ms Result: PASS 350s START /main/json/ - object_set 350s END /main/json/ - object_set Time: <1ms Result: PASS 350s START /main/json/ - object_alloc 350s END /main/json/ - object_alloc Time: <1ms Result: PASS 350s START /main/json/ - array_null 350s END /main/json/ - array_null Time: <1ms Result: PASS 350s START /main/json/ - array_extend 350s END /main/json/ - array_extend Time: <1ms Result: PASS 350s START /main/json/ - array_clear 350s END /main/json/ - array_clear Time: <1ms Result: PASS 350s START /main/json/ - array_remove 350s END /main/json/ - array_remove Time: <1ms Result: PASS 350s START /main/json/ - array_set 350s END /main/json/ - array_set Time: <1ms Result: PASS 350s START /main/json/ - array_insert 350s END /main/json/ - array_insert Time: <1ms Result: PASS 350s START /main/json/ - array_append 350s END /main/json/ - array_append Time: <1ms Result: PASS 350s START /main/json/ - array_create 350s END /main/json/ - array_create Time: <1ms Result: PASS 350s START /main/json/ - non_int 350s END /main/json/ - non_int Time: <1ms Result: PASS 350s START /main/json/ - type_int 350s END /main/json/ - type_int Time: <1ms Result: PASS 350s START /main/json/ - stringf 350s END /main/json/ - stringf Time: <1ms Result: PASS 350s START /main/json/ - string_null 350s END /main/json/ - string_null Time: <1ms Result: PASS 350s START /main/json/ - type_string 350s END /main/json/ - type_string Time: <1ms Result: PASS 350s START /main/json/ - null_val 350s END /main/json/ - null_val Time: <1ms Result: PASS 350s START /main/json/ - type_null 350s END /main/json/ - type_null Time: <1ms Result: PASS 350s START /main/json/ - type_bool1 350s END /main/json/ - type_bool1 Time: <1ms Result: PASS 350s START /main/json/ - type_bool0 350s END /main/json/ - type_bool0 Time: <1ms Result: PASS 350s START /main/json/ - type_true 350s END /main/json/ - type_true Time: <1ms Result: PASS 350s START /main/json/ - type_false 350s END /main/json/ - type_false Time: <1ms Result: PASS 350s START /main/linkedlists/ - double_ll_tests 350s END /main/linkedlists/ - double_ll_tests Time: <1ms Result: PASS 350s START /main/linkedlists/ - ll_tests 350s END /main/linkedlists/ - ll_tests Time: <1ms Result: PASS 350s START /main/lock/ - named_lock_test 350s [test_named_lock.c:named_lock_test:80]: This test should take about 3 seconds 352s END /main/lock/ - named_lock_test Time: 3000ms Result: PASS 352s START /main/lock/ - cleanup_order_test 352s [test_scoped_lock.c:test_ref:149]: Ref is occurring 352s [test_scoped_lock.c:test_lock:117]: Lock is occurring 352s [test_scoped_lock.c:test_unlock:133]: Unlock is occurring 352s [test_scoped_lock.c:test_unref:166]: Unref is occurring 352s [test_scoped_lock.c:test_ref:149]: Ref is occurring 352s [test_scoped_lock.c:test_lock:117]: Lock is occurring 352s [test_scoped_lock.c:test_unlock:133]: Unlock is occurring 352s [test_scoped_lock.c:test_unref:166]: Unref is occurring 352s END /main/lock/ - cleanup_order_test Time: <1ms Result: PASS 352s START /main/lock/ - lock_test 352s END /main/lock/ - lock_test Time: <1ms Result: PASS 352s START /main/logging/ - scope_test 352s END /main/logging/ - scope_test Time: <1ms Result: PASS 352s START /main/media_cache/ - create_update_off_nominal 352s END /main/media_cache/ - create_update_off_nominal Time: <1ms Result: PASS 352s START /main/media_cache/ - create_update_metadata 352s [test_media_cache.c:create_update_metadata:364]: Got /tmp/test-media-cache-LfNeIS for second file path 352s END /main/media_cache/ - create_update_metadata Time: 2ms Result: PASS 352s START /main/media_cache/ - create_update_nominal 352s [test_media_cache.c:create_update_nominal:235]: Creating resource with /tmp/test-media-cache-Uc2EQ4 352s [test_media_cache.c:create_update_nominal:240]: Got /tmp/test-media-cache-Uc2EQ4 for first file path 352s [test_media_cache.c:create_update_nominal:244]: Creating resource with /tmp/test-media-cache-dr8eKn 352s [test_media_cache.c:create_update_nominal:249]: Got /tmp/test-media-cache-dr8eKn for second file path 352s END /main/media_cache/ - create_update_nominal Time: <1ms Result: PASS 352s START /main/media_cache/ - exists_off_nominal 352s END /main/media_cache/ - exists_off_nominal Time: <1ms Result: PASS 352s START /main/media_cache/ - exists_nominal 352s END /main/media_cache/ - exists_nominal Time: <1ms Result: PASS 352s START /main/netsock2/ - split_hostport 352s END /main/netsock2/ - split_hostport Time: <1ms Result: PASS 352s START /main/netsock2/ - parsing 352s END /main/netsock2/ - parsing Time: <1ms Result: PASS 352s START /main/optional_api/ - test_provide_last 353s END /main/optional_api/ - test_provide_last Time: <1ms Result: PASS 353s START /main/optional_api/ - test_provide_first 353s END /main/optional_api/ - test_provide_first Time: <1ms Result: PASS 353s START /main/pbx/ - pattern_match_test 353s [test_pbx.c:test_exten:183]: Successfully matched 200 to exten _2. in context test_pattern with the old pattern match engine 353s [test_pbx.c:test_exten:183]: Successfully matched 2000 to exten 2000 in context test_pattern with the old pattern match engine 353s [test_pbx.c:test_exten:183]: Successfully matched 2000 to exten 2000 in context test_pattern with the old pattern match engine 353s [test_pbx.c:test_exten:183]: Successfully matched 2000 to exten 2000 in context test_pattern_include with the old pattern match engine 353s [test_pbx.c:test_exten:183]: Successfully matched 200 to exten _2. in context test_pattern with the new pattern match engine 353s [test_pbx.c:test_exten:183]: Successfully matched 2000 to exten 2000 in context test_pattern with the new pattern match engine 353s [test_pbx.c:test_exten:183]: Successfully matched 2000 to exten 2000 in context test_pattern with the new pattern match engine 353s [test_pbx.c:test_exten:183]: Successfully matched 2000 to exten 2000 in context test_pattern_include with the new pattern match engine 353s END /main/pbx/ - pattern_match_test Time: <1ms Result: PASS 353s START /main/pbx/ - test_substitution 353s [test_substitution.c:test_substitution:244]: Testing variable substitution ... 353s [test_substitution.c:test_chan_integer:65]: Tested '${CALLINGANI2}' . . . . . passed 353s [test_substitution.c:test_chan_integer:65]: Tested '${CALLINGTON}' . . . . . passed 353s [test_substitution.c:test_chan_integer:65]: Tested '${CALLINGTNS}' . . . . . passed 353s [test_substitution.c:test_chan_integer_accessor:89]: Tested '${HANGUPCAUSE}' . . . . . passed 353s [test_substitution.c:test_chan_integer_accessor:89]: Tested '${PRIORITY}' . . . . . passed 353s [test_substitution.c:test_chan_string:115]: Tested '${CONTEXT}' . . . . . passed 353s [test_substitution.c:test_chan_string:115]: Tested '${EXTEN}' . . . . . passed 353s [test_substitution.c:test_chan_variable:144]: Tested '${CHANNEL(language)}' . . . . . passed 353s [test_substitution.c:test_chan_variable:144]: Tested '${CHANNEL(musicclass)}' . . . . . passed 353s [test_substitution.c:test_chan_variable:144]: Tested '${CHANNEL(parkinglot)}' . . . . . passed 353s [test_substitution.c:test_chan_variable:144]: Tested '${CALLERID(name)}' . . . . . passed 353s [test_substitution.c:test_chan_variable:144]: Tested '${CURLOPT(proxyuserpwd)}' . . . . . passed 353s [test_substitution.c:test_chan_variable:144]: Tested '${CDR(foo)}' . . . . . passed 353s [test_substitution.c:test_chan_variable:144]: Tested '${ENV(foo)}' . . . . . passed 353s [test_substitution.c:test_chan_variable:144]: Tested '${GLOBAL(foo)}' . . . . . passed 353s [test_substitution.c:test_chan_variable:144]: Tested '${GROUP()}' . . . . . passed 353s [test_substitution.c:test_2way_function:193]: Tested '${AES_ENCRYPT(abcdefghijklmnop,)}' and '${AES_DECRYPT(abcdefghijklmnop,)}' . . . . . passed 353s [test_substitution.c:test_2way_function:193]: Tested '${BASE64_ENCODE()}' and '${BASE64_DECODE()}' . . . . . passed 353s [test_substitution.c:test_expected_result:215]: Tested '123123' ('${foo}${foo}') == '123123' . . . . . passed 353s [test_substitution.c:test_expected_result:215]: Tested 'A123A123A' ('A${foo}A${foo}A') == 'A123A123A' . . . . . passed 353s [test_substitution.c:test_expected_result:215]: Tested 'A123A' ('A${${bar}}A') == 'A123A' . . . . . passed 353s [test_substitution.c:test_expected_result:215]: Tested 'A123A' ('A${${baz}o}A') == 'A123A' . . . . . passed 353s [test_substitution.c:test_expected_result:215]: Tested 'A23A' ('A${${baz}o:1}A') == 'A23A' . . . . . passed 353s [test_substitution.c:test_expected_result:215]: Tested 'A2A' ('A${${baz}o:1:1}A') == 'A2A' . . . . . passed 353s [test_substitution.c:test_expected_result:215]: Tested 'A2A' ('A${${baz}o:1:-1}A') == 'A2A' . . . . . passed 353s [test_substitution.c:test_expected_result:215]: Tested 'A3A' ('A${${baz}o:-1:1}A') == 'A3A' . . . . . passed 353s [test_substitution.c:test_expected_result:215]: Tested 'A2A' ('A${${baz}o:-2:1}A') == 'A2A' . . . . . passed 353s [test_substitution.c:test_expected_result:215]: Tested 'A2A' ('A${${baz}o:-2:-1}A') == 'A2A' . . . . . passed 353s [test_substitution.c:test_expected_result:215]: Tested 'cd&ef' ('${LISTFILTER(list1,&,ab)}') == 'cd&ef' . . . . . passed 353s [test_substitution.c:test_expected_result:215]: Tested 'ab&ef' ('${LISTFILTER(list1,&,cd)}') == 'ab&ef' . . . . . passed 353s [test_substitution.c:test_expected_result:215]: Tested 'ab&cd' ('${LISTFILTER(list1,&,ef)}') == 'ab&cd' . . . . . passed 353s [test_substitution.c:test_expected_result:215]: Tested 'ab&cd&ef' ('${LISTFILTER(list1,&,gh)}') == 'ab&cd&ef' . . . . . passed 353s [test_substitution.c:test_expected_result:215]: Tested 'ab&cd&ef' ('${LISTFILTER(list1,&,c)}') == 'ab&cd&ef' . . . . . passed 353s [test_substitution.c:test_expected_result:215]: Tested 'ab&cd&ef' ('${LISTFILTER(list1,&,d)}') == 'ab&cd&ef' . . . . . passed 353s [test_substitution.c:test_expected_result:215]: Tested '' ('${LISTFILTER(list2,&,ab)}') == '' . . . . . passed 353s [test_substitution.c:test_expected_result:215]: Tested '' ('${LISTFILTER(list_empty,&,ab)}') == '' . . . . . passed 353s [test_substitution.c:test_expected_result:215]: Tested '123,456' ('${SHELL(printf '%d' 123)},${SHELL(printf '%d' 456)}') == '123,456' . . . . . passed 353s [test_substitution.c:test_expected_result:215]: Tested '123,,456' ('${foo},${CDR(answer)},${SHELL(printf '%d' 456)}') == '123,,456' . . . . . passed 353s [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 353s [test_substitution.c:test_expected_result:215]: Tested '123,,' ('${foo},${this_does_not_exist},${THIS_DOES_NOT_EXIST(either)}') == '123,,' . . . . . passed 353s [test_substitution.c:test_chan_function:168]: Tested '${BLACKLIST(foo)}' . . . . . passed 353s [test_substitution.c:test_chan_function:168]: Tested '${EVAL(foo)}' . . . . . passed 353s [test_substitution.c:test_chan_function:168]: Tested '${FIELDNUM(foo)}' . . . . . passed 353s [test_substitution.c:test_chan_function:168]: Tested '${FIELDQTY(foo)}' . . . . . passed 353s [test_substitution.c:test_chan_function:168]: Tested '${HASHKEYS(foo)}' . . . . . passed 353s [test_substitution.c:test_chan_function:168]: Tested '${IMPORT(foo)}' . . . . . passed 353s [test_substitution.c:test_chan_function:168]: Tested '${PP_EACH_USER(foo)}' . . . . . passed 353s [test_substitution.c:test_chan_function:168]: Tested '${TOLOWER(foo)}' . . . . . passed 353s [test_substitution.c:test_chan_function:168]: Tested '${TOUPPER(foo)}' . . . . . passed 353s END /main/pbx/ - test_substitution Time: 9ms Result: PASS 353s START /main/pbx/ - test_MATH_function 353s [func_math.c:test_MATH_function:682]: Testing MATH() substitution ... 353s END /main/pbx/ - test_MATH_function Time: <1ms Result: PASS 353s START /main/pbx/ - variable_substrings 353s END /main/pbx/ - variable_substrings Time: <1ms Result: PASS 353s START /main/poll/ - poll_test 353s [test_poll.c:poll_test:95]: Creating handle that should NEVER block on write 353s [test_poll.c:poll_test:101]: Creating handle that should NEVER block on read 353s [test_poll.c:poll_test:108]: Creating handle that should block on read 353s [test_poll.c:poll_test:168]: Starting thread to ensure we don't block forever 353s [test_poll.c:poll_test:194]: Cancelling failsafe thread. 353s END /main/poll/ - poll_test Time: <1ms Result: PASS 353s START /main/presence/ - channel_presence 353s END /main/presence/ - channel_presence Time: <1ms Result: PASS 353s START /main/sample/ - sample_test 353s [test_skel.c:sample_test:57]: Executing sample test... 353s END /main/sample/ - sample_test Time: <1ms Result: PASS 353s START /main/sched/ - sched_test_freebird 353s [test_sched.c:sched_test_freebird:440]: Received signal, calling Scedule and UNREF 353s [test_sched.c:sched_test_freebird:441]: ID: 1 355s [test_sched.c:sched_test_freebird:448]: Correct number of references '2' 355s END /main/sched/ - sched_test_freebird Time: 3000ms Result: PASS 355s START /main/sched/ - sched_test_order 356s END /main/sched/ - sched_test_order Time: 400ms Result: PASS 356s START /main/sorcery/ - wizard_read_only 356s END /main/sorcery/ - wizard_read_only Time: <1ms Result: PASS 356s START /main/sorcery/ - wizard_observation 356s END /main/sorcery/ - wizard_observation Time: <1ms Result: PASS 356s START /main/sorcery/ - instance_observation 356s END /main/sorcery/ - instance_observation Time: <1ms Result: PASS 356s START /main/sorcery/ - global_observation 356s END /main/sorcery/ - global_observation Time: <1ms Result: PASS 356s START /main/sorcery/ - object_field_registered 356s END /main/sorcery/ - object_field_registered Time: <1ms Result: PASS 356s START /main/sorcery/ - dialplan_function 356s END /main/sorcery/ - dialplan_function Time: <1ms Result: PASS 356s START /main/sorcery/ - configuration_file_wizard_retrieve_multiple_all 356s END /main/sorcery/ - configuration_file_wizard_retrieve_multiple_all Time: <1ms Result: PASS 356s START /main/sorcery/ - configuration_file_wizard_retrieve_multiple 356s END /main/sorcery/ - configuration_file_wizard_retrieve_multiple Time: <1ms Result: PASS 356s START /main/sorcery/ - configuration_file_wizard_retrieve_field 356s END /main/sorcery/ - configuration_file_wizard_retrieve_field Time: <1ms Result: PASS 356s START /main/sorcery/ - configuration_file_wizard_with_criteria 356s END /main/sorcery/ - configuration_file_wizard_with_criteria Time: <1ms Result: PASS 356s START /main/sorcery/ - configuration_file_wizard_with_file_integrity 356s END /main/sorcery/ - configuration_file_wizard_with_file_integrity Time: <1ms Result: PASS 356s START /main/sorcery/ - configuration_file_wizard 356s END /main/sorcery/ - configuration_file_wizard Time: <1ms Result: PASS 356s START /main/sorcery/ - object_type_observer 356s END /main/sorcery/ - object_type_observer Time: <1ms Result: PASS 356s START /main/sorcery/ - caching_wizard_behavior 356s END /main/sorcery/ - caching_wizard_behavior Time: <1ms Result: PASS 356s START /main/sorcery/ - object_is_stale 356s END /main/sorcery/ - object_is_stale Time: <1ms Result: PASS 356s START /main/sorcery/ - object_delete_uncreated 356s END /main/sorcery/ - object_delete_uncreated Time: <1ms Result: PASS 356s START /main/sorcery/ - object_delete 356s END /main/sorcery/ - object_delete Time: <1ms Result: PASS 356s START /main/sorcery/ - object_update_uncreated 356s END /main/sorcery/ - object_update_uncreated Time: <1ms Result: PASS 356s START /main/sorcery/ - object_update 356s END /main/sorcery/ - object_update Time: <1ms Result: PASS 356s START /main/sorcery/ - object_retrieve_regex 356s END /main/sorcery/ - object_retrieve_regex Time: <1ms Result: PASS 356s START /main/sorcery/ - object_retrieve_multiple_field 356s END /main/sorcery/ - object_retrieve_multiple_field Time: <1ms Result: PASS 356s START /main/sorcery/ - object_retrieve_multiple_all 356s END /main/sorcery/ - object_retrieve_multiple_all Time: <1ms Result: PASS 356s START /main/sorcery/ - object_retrieve_field 356s END /main/sorcery/ - object_retrieve_field Time: <1ms Result: PASS 356s START /main/sorcery/ - object_retrieve_id 356s END /main/sorcery/ - object_retrieve_id Time: <1ms Result: PASS 356s START /main/sorcery/ - object_create 356s END /main/sorcery/ - object_create Time: <1ms Result: PASS 356s START /main/sorcery/ - changeset_create_unchanged 356s END /main/sorcery/ - changeset_create_unchanged Time: <1ms Result: PASS 356s START /main/sorcery/ - changeset_create 356s END /main/sorcery/ - changeset_create Time: <1ms Result: PASS 356s START /main/sorcery/ - extended_fields 356s END /main/sorcery/ - extended_fields Time: <1ms Result: PASS 356s START /main/sorcery/ - objectset_apply_fields 356s END /main/sorcery/ - objectset_apply_fields Time: <1ms Result: PASS 356s START /main/sorcery/ - objectset_transform 356s END /main/sorcery/ - objectset_transform Time: <1ms Result: PASS 356s START /main/sorcery/ - objectset_apply_invalid 356s END /main/sorcery/ - objectset_apply_invalid Time: <1ms Result: PASS 356s START /main/sorcery/ - objectset_apply_handler 356s END /main/sorcery/ - objectset_apply_handler Time: <1ms Result: PASS 356s START /main/sorcery/ - objectset_apply 356s END /main/sorcery/ - objectset_apply Time: <1ms Result: PASS 356s START /main/sorcery/ - objectset_create_regex 356s END /main/sorcery/ - objectset_create_regex Time: <1ms Result: PASS 356s START /main/sorcery/ - objectset_json_create 356s END /main/sorcery/ - objectset_json_create Time: <1ms Result: PASS 356s START /main/sorcery/ - objectset_create 356s END /main/sorcery/ - objectset_create Time: <1ms Result: PASS 356s START /main/sorcery/ - object_diff_native 356s END /main/sorcery/ - object_diff_native Time: <1ms Result: PASS 356s START /main/sorcery/ - object_diff 356s END /main/sorcery/ - object_diff Time: <1ms Result: PASS 356s START /main/sorcery/ - object_copy_native 356s END /main/sorcery/ - object_copy_native Time: <1ms Result: PASS 356s START /main/sorcery/ - object_copy 356s END /main/sorcery/ - object_copy Time: <1ms Result: PASS 356s START /main/sorcery/ - object_alloc_without_id 356s END /main/sorcery/ - object_alloc_without_id Time: <1ms Result: PASS 356s START /main/sorcery/ - object_alloc_with_id 356s END /main/sorcery/ - object_alloc_with_id Time: <1ms Result: PASS 356s START /main/sorcery/ - object_fields_register 356s END /main/sorcery/ - object_fields_register Time: <1ms Result: PASS 356s START /main/sorcery/ - object_field_register 356s END /main/sorcery/ - object_field_register Time: <1ms Result: PASS 356s START /main/sorcery/ - object_register_without_mapping 356s END /main/sorcery/ - object_register_without_mapping Time: <1ms Result: PASS 356s START /main/sorcery/ - object_register 356s END /main/sorcery/ - object_register Time: <1ms Result: PASS 356s START /main/sorcery/ - apply_config 356s END /main/sorcery/ - apply_config Time: <1ms Result: PASS 356s START /main/sorcery/ - apply_default 356s END /main/sorcery/ - apply_default Time: <1ms Result: PASS 356s START /main/sorcery/ - open 356s END /main/sorcery/ - open Time: <1ms Result: PASS 356s START /main/sorcery/ - wizard_registration 356s END /main/sorcery/ - wizard_registration Time: <1ms Result: PASS 356s START /main/sorcery/ - wizard_apply_and_insert 356s END /main/sorcery/ - wizard_apply_and_insert Time: <1ms Result: PASS 356s START /main/stdtime/ - time_create_by_unit_str 356s END /main/stdtime/ - time_create_by_unit_str Time: <1ms Result: PASS 356s START /main/stdtime/ - time_create_by_unit 356s END /main/stdtime/ - time_create_by_unit Time: <1ms Result: PASS 356s START /main/stdtime/ - time_str_to_unit 356s END /main/stdtime/ - time_str_to_unit Time: <1ms Result: PASS 356s START /main/stdtime/ - time_tv_to_usec 356s END /main/stdtime/ - time_tv_to_usec Time: <1ms Result: PASS 356s START /main/stdtime/ - timezone_watch 356s [test_time.c:test_timezone_watch:82]: Executing deletion test... 356s [test_time.c:test_timezone_watch:90]: Querying timezone /tmp/timezone.ce0HgP/test 357s [test_time.c:test_timezone_watch:90]: Querying timezone /tmp/timezone.ce0HgP/test 357s [test_time.c:test_timezone_watch:82]: Executing symlink test... 357s [test_time.c:test_timezone_watch:90]: Querying timezone /tmp/timezone.ce0HgP/test 358s [test_time.c:test_timezone_watch:90]: Querying timezone /tmp/timezone.ce0HgP/test 358s END /main/stdtime/ - timezone_watch Time: 2240ms Result: PASS 358s START /main/stream/ - stream_topology_map_create 358s END /main/stream/ - stream_topology_map_create Time: <1ms Result: PASS 358s START /main/stream/ - format_cap_from_stream_topology 358s END /main/stream/ - format_cap_from_stream_topology Time: <1ms Result: PASS 358s START /main/stream/ - stream_topology_change_request_from_channel 358s END /main/stream/ - stream_topology_change_request_from_channel Time: <1ms Result: PASS 358s START /main/stream/ - stream_topology_change_request_from_application 358s END /main/stream/ - stream_topology_change_request_from_application Time: <1ms Result: PASS 358s START /main/stream/ - stream_topology_change_request_from_channel_non_multistream 358s END /main/stream/ - stream_topology_change_request_from_channel_non_multistream Time: <1ms Result: PASS 358s START /main/stream/ - stream_topology_change_request_from_application_non_multistream 358s END /main/stream/ - stream_topology_change_request_from_application_non_multistream Time: <1ms Result: PASS 358s START /main/stream/ - stream_read_multistream 358s [test_stream.c:read_test:1726]: ChanType: MULTI ReadType: NON-STREAM Streams: 2 Frames: 16 Frames per read: 1 Expected Nulls: 0 358s [test_stream.c:read_test:1759]: Frames read: 16 NULL frames: 0 358s [test_stream.c:read_test:1726]: ChanType: MULTI ReadType: STREAM Streams: 2 Frames: 16 Frames per read: 1 Expected Nulls: 0 358s [test_stream.c:read_test:1759]: Frames read: 16 NULL frames: 0 358s [test_stream.c:read_test:1726]: ChanType: MULTI ReadType: NON-STREAM Streams: 4 Frames: 16 Frames per read: 1 Expected Nulls: 8 358s [test_stream.c:read_test:1759]: Frames read: 16 NULL frames: 8 358s [test_stream.c:read_test:1726]: ChanType: MULTI ReadType: STREAM Streams: 4 Frames: 16 Frames per read: 1 Expected Nulls: 0 358s [test_stream.c:read_test:1759]: Frames read: 16 NULL frames: 0 358s [test_stream.c:read_test:1726]: ChanType: MULTI ReadType: NON-STREAM Streams: 2 Frames: 16 Frames per read: 3 Expected Nulls: 0 358s [test_stream.c:read_test:1759]: Frames read: 16 NULL frames: 0 358s [test_stream.c:read_test:1726]: ChanType: MULTI ReadType: STREAM Streams: 2 Frames: 16 Frames per read: 3 Expected Nulls: 0 358s [test_stream.c:read_test:1759]: Frames read: 16 NULL frames: 0 358s [test_stream.c:read_test:1726]: ChanType: MULTI ReadType: NON-STREAM Streams: 4 Frames: 16 Frames per read: 3 Expected Nulls: 8 358s [test_stream.c:read_test:1759]: Frames read: 16 NULL frames: 8 358s [test_stream.c:read_test:1726]: ChanType: MULTI ReadType: STREAM Streams: 4 Frames: 16 Frames per read: 3 Expected Nulls: 0 358s [test_stream.c:read_test:1759]: Frames read: 16 NULL frames: 0 358s END /main/stream/ - stream_read_multistream Time: 1ms Result: PASS 358s START /main/stream/ - stream_read_non_multistream 358s [test_stream.c:read_test:1726]: ChanType: NON-MULTI ReadType: NON-STREAM Streams: 2 Frames: 16 Frames per read: 1 Expected Nulls: 0 358s [test_stream.c:read_test:1759]: Frames read: 16 NULL frames: 0 358s [test_stream.c:read_test:1726]: ChanType: NON-MULTI ReadType: STREAM Streams: 2 Frames: 16 Frames per read: 1 Expected Nulls: 0 358s [test_stream.c:read_test:1759]: Frames read: 16 NULL frames: 0 358s [test_stream.c:read_test:1726]: ChanType: NON-MULTI ReadType: NON-STREAM Streams: 2 Frames: 16 Frames per read: 3 Expected Nulls: 0 358s [test_stream.c:read_test:1759]: Frames read: 16 NULL frames: 0 358s [test_stream.c:read_test:1726]: ChanType: NON-MULTI ReadType: STREAM Streams: 2 Frames: 16 Frames per read: 3 Expected Nulls: 0 358s [test_stream.c:read_test:1759]: Frames read: 16 NULL frames: 0 358s END /main/stream/ - stream_read_non_multistream Time: <1ms Result: PASS 358s START /main/stream/ - stream_write_multistream 358s END /main/stream/ - stream_write_multistream Time: <1ms Result: PASS 358s START /main/stream/ - stream_write_non_multistream 358s END /main/stream/ - stream_write_non_multistream Time: <1ms Result: PASS 358s START /main/stream/ - stream_topology_channel_set 358s END /main/stream/ - stream_topology_channel_set Time: <1ms Result: PASS 358s START /main/stream/ - stream_topology_create_from_channel_nativeformats 358s END /main/stream/ - stream_topology_create_from_channel_nativeformats Time: <1ms Result: PASS 358s START /main/stream/ - stream_topology_get_first_stream_by_type 358s END /main/stream/ - stream_topology_get_first_stream_by_type Time: <1ms Result: PASS 358s START /main/stream/ - stream_topology_create_from_format_cap 358s END /main/stream/ - stream_topology_create_from_format_cap Time: <1ms Result: PASS 358s START /main/stream/ - stream_topology_del_stream 358s END /main/stream/ - stream_topology_del_stream Time: <1ms Result: PASS 358s START /main/stream/ - stream_topology_set_stream 358s END /main/stream/ - stream_topology_set_stream Time: <1ms Result: PASS 358s START /main/stream/ - stream_topology_append_stream 358s END /main/stream/ - stream_topology_append_stream Time: <1ms Result: PASS 358s START /main/stream/ - stream_topology_clone 358s END /main/stream/ - stream_topology_clone Time: <1ms Result: PASS 358s START /main/stream/ - stream_topology_create 358s END /main/stream/ - stream_topology_create Time: <1ms Result: PASS 358s START /main/stream/ - stream_metadata 358s END /main/stream/ - stream_metadata Time: <1ms Result: PASS 358s START /main/stream/ - stream_set_state 358s END /main/stream/ - stream_set_state Time: <1ms Result: PASS 358s START /main/stream/ - stream_set_formats 358s END /main/stream/ - stream_set_formats Time: <1ms Result: PASS 358s START /main/stream/ - stream_set_type 358s END /main/stream/ - stream_set_type Time: <1ms Result: PASS 358s START /main/stream/ - stream_create_no_name 358s END /main/stream/ - stream_create_no_name Time: <1ms Result: PASS 358s START /main/stream/ - stream_create 358s END /main/stream/ - stream_create Time: <1ms Result: PASS 358s START /main/strings/ - in_delimited_string 358s END /main/strings/ - in_delimited_string Time: <1ms Result: PASS 358s START /main/strings/ - temp_strings 358s END /main/strings/ - temp_strings Time: <1ms Result: PASS 358s START /main/strings/ - strings_match 358s END /main/strings/ - strings_match Time: <1ms Result: PASS 358s START /main/strings/ - escape 358s END /main/strings/ - escape Time: <1ms Result: PASS 358s START /main/strings/ - escape_semicolons 358s END /main/strings/ - escape_semicolons Time: <1ms Result: PASS 358s START /main/strings/ - strsep_quoted 358s END /main/strings/ - strsep_quoted Time: <1ms Result: PASS 358s START /main/strings/ - strsep 358s END /main/strings/ - strsep Time: <1ms Result: PASS 358s START /main/strings/ - ends_with 358s END /main/strings/ - ends_with Time: <1ms Result: PASS 358s START /main/strings/ - begins_with 358s END /main/strings/ - begins_with Time: <1ms Result: PASS 358s START /main/strings/ - str_test 358s END /main/strings/ - str_test Time: <1ms Result: PASS 358s START /main/taskprocessor/ - serializer_pool 362s END /main/taskprocessor/ - serializer_pool Time: 4000ms Result: PASS 362s START /main/taskprocessor/ - taskprocessor_push_local 362s END /main/taskprocessor/ - taskprocessor_push_local Time: <1ms Result: PASS 362s START /main/taskprocessor/ - taskprocessor_shutdown 362s END /main/taskprocessor/ - taskprocessor_shutdown Time: <1ms Result: PASS 362s START /main/taskprocessor/ - taskprocessor_listener 362s END /main/taskprocessor/ - taskprocessor_listener Time: <1ms Result: PASS 362s START /main/taskprocessor/ - subsystem_alert 362s [test_taskprocessor.c:subsystem_alert:224]: Pushing task 1 362s [test_taskprocessor.c:subsystem_alert:224]: Pushing task 2 362s [test_taskprocessor.c:subsystem_alert:224]: Pushing task 3 362s [test_taskprocessor.c:subsystem_alert:224]: Pushing task 4 362s [test_taskprocessor.c:subsystem_alert:224]: Pushing task 5 362s [test_taskprocessor.c:subsystem_alert:224]: Pushing task 6 362s [test_taskprocessor.c:subsystem_alert:244]: Subsystem alert triggered unexpectedly at 5 362s [test_taskprocessor.c:subsystem_alert:248]: Global alert triggered unexpectedly at 5 362s [test_taskprocessor.c:subsystem_alert:224]: Pushing task 7 362s [test_taskprocessor.c:subsystem_alert:237]: Subsystem alert triggered correctly at 6 362s [test_taskprocessor.c:subsystem_alert:240]: Global alert triggered correctly at 6 362s [test_taskprocessor.c:subsystem_alert:224]: Pushing task 8 362s [test_taskprocessor.c:subsystem_alert:224]: Pushing task 9 362s [test_taskprocessor.c:subsystem_alert:224]: Pushing task 10 362s [test_taskprocessor.c:subsystem_alert:266]: Waiting on task 1 363s [test_taskprocessor.c:subsystem_alert:266]: Waiting on task 2 363s [test_taskprocessor.c:subsystem_alert:266]: Waiting on task 3 364s [test_taskprocessor.c:subsystem_alert:266]: Waiting on task 4 364s [test_taskprocessor.c:subsystem_alert:266]: Waiting on task 5 365s [test_taskprocessor.c:subsystem_alert:266]: Waiting on task 6 365s [test_taskprocessor.c:subsystem_alert:279]: Subsystem alert cleared correctly at 3 365s [test_taskprocessor.c:subsystem_alert:282]: Global alert cleared correctly at 3 365s [test_taskprocessor.c:subsystem_alert:266]: Waiting on task 7 366s [test_taskprocessor.c:subsystem_alert:266]: Waiting on task 8 366s [test_taskprocessor.c:subsystem_alert:266]: Waiting on task 9 367s [test_taskprocessor.c:subsystem_alert:266]: Waiting on task 10 367s END /main/taskprocessor/ - subsystem_alert Time: 5001ms Result: FAIL 367s START /main/taskprocessor/ - default_taskprocessor_load 367s END /main/taskprocessor/ - default_taskprocessor_load Time: 58ms Result: PASS 367s START /main/taskprocessor/ - default_taskprocessor 367s END /main/taskprocessor/ - default_taskprocessor Time: <1ms Result: PASS 367s START /main/test/ - registrations 367s END /main/test/ - registrations Time: <1ms Result: PASS 367s START /main/test_capture/ - test_capture_false 367s [test_capture.c:test_capture_false:120]: Executing false exit test... 367s END /main/test_capture/ - test_capture_false Time: 7ms Result: PASS 367s START /main/test_capture/ - test_capture_true 367s [test_capture.c:test_capture_true:61]: Executing true exit test... 367s END /main/test_capture/ - test_capture_true Time: 5ms Result: PASS 367s START /main/test_capture/ - test_capture_stdout_stderr 367s [test_capture.c:test_capture_stdout_stderr:318]: Executing stdout/stderr test... 367s END /main/test_capture/ - test_capture_stdout_stderr Time: 5ms Result: PASS 367s START /main/test_capture/ - test_capture_with_dynamic 367s [test_capture.c:test_capture_with_dynamic:249]: Executing dynamic argument test... 367s END /main/test_capture/ - test_capture_with_dynamic Time: 6ms Result: PASS 367s START /main/test_capture/ - test_capture_with_stdin 367s [test_capture.c:test_capture_with_stdin:183]: Executing stdin test... 367s END /main/test_capture/ - test_capture_with_stdin Time: 6ms Result: PASS 367s START /main/threadpool/ - threadpool_serializer_dupe 367s END /main/threadpool/ - threadpool_serializer_dupe Time: <1ms Result: PASS 367s START /main/threadpool/ - threadpool_serializer 368s END /main/threadpool/ - threadpool_serializer Time: 1000ms Result: PASS 368s START /main/threadpool/ - more_destruction 368s END /main/threadpool/ - more_destruction Time: <1ms Result: PASS 368s START /main/threadpool/ - task_distribution 368s END /main/threadpool/ - task_distribution Time: <1ms Result: PASS 368s START /main/threadpool/ - reactivation 368s END /main/threadpool/ - reactivation Time: <1ms Result: PASS 368s START /main/threadpool/ - max_size 368s END /main/threadpool/ - max_size Time: <1ms Result: PASS 368s START /main/threadpool/ - auto_increment 368s END /main/threadpool/ - auto_increment Time: <1ms Result: PASS 368s START /main/threadpool/ - one_thread_multiple_tasks 368s END /main/threadpool/ - one_thread_multiple_tasks Time: <1ms Result: PASS 368s START /main/threadpool/ - one_thread_one_task 368s END /main/threadpool/ - one_thread_one_task Time: <1ms Result: PASS 368s START /main/threadpool/ - one_task_one_thread 368s END /main/threadpool/ - one_task_one_thread Time: <1ms Result: PASS 368s START /main/threadpool/ - thread_timeout_thrash 399s END /main/threadpool/ - thread_timeout_thrash Time: 31005ms Result: PASS 399s START /main/threadpool/ - thread_timeout 401s END /main/threadpool/ - thread_timeout Time: 2000ms Result: PASS 401s START /main/threadpool/ - thread_destruction 401s END /main/threadpool/ - thread_destruction Time: <1ms Result: PASS 401s START /main/threadpool/ - thread_creation 401s END /main/threadpool/ - thread_creation Time: <1ms Result: PASS 401s START /main/threadpool/ - initial_threads 401s END /main/threadpool/ - initial_threads Time: <1ms Result: PASS 401s START /main/threadpool/ - push 401s END /main/threadpool/ - push Time: <1ms Result: PASS 401s START /main/uri/ - uri_default_http_secure 401s END /main/uri/ - uri_default_http_secure Time: <1ms Result: PASS 401s START /main/uri/ - uri_default_http 401s END /main/uri/ - uri_default_http Time: <1ms Result: PASS 401s START /main/uri/ - uri_parse 401s END /main/uri/ - uri_parse Time: <1ms Result: PASS 401s START /main/utf8/ - replace_invalid 401s END /main/utf8/ - replace_invalid Time: <1ms Result: PASS 401s START /main/utf8/ - utf8_validator 401s END /main/utf8/ - utf8_validator Time: <1ms Result: PASS 401s START /main/utf8/ - copy_string 401s END /main/utf8/ - copy_string Time: <1ms Result: PASS 401s START /main/utf8/ - is_valid 401s END /main/utf8/ - is_valid Time: <1ms Result: PASS 401s START /main/utils/ - quote_unescaping 401s END /main/utils/ - quote_unescaping Time: <1ms Result: PASS 401s START /main/utils/ - quote_mutation 401s END /main/utils/ - quote_mutation Time: <1ms Result: PASS 401s START /main/utils/ - crypt_test 401s END /main/utils/ - crypt_test Time: 14ms Result: PASS 401s START /main/utils/ - safe_mkdir_test 401s END /main/utils/ - safe_mkdir_test Time: <1ms Result: PASS 401s START /main/utils/ - base64_test 401s END /main/utils/ - base64_test Time: <1ms Result: PASS 401s START /main/utils/ - sha1_test 401s [test_utils.c:sha1_test:250]: Testing SHA1 ... 401s END /main/utils/ - sha1_test Time: <1ms Result: PASS 401s START /main/utils/ - md5_test 401s [test_utils.c:md5_test:205]: Testing MD5 ... 401s END /main/utils/ - md5_test Time: <1ms Result: PASS 401s START /main/utils/ - quoted_escape_test 401s END /main/utils/ - quoted_escape_test Time: <1ms Result: PASS 401s START /main/utils/ - uri_encode_decode_test 401s END /main/utils/ - uri_encode_decode_test Time: <1ms Result: PASS 401s START /main/utils/ - string_field_aggregate_test 401s [test_stringfields.c:string_field_aggregate_test:392]: Structures 3 embedded pool initialized successfully. 401s [test_stringfields.c:string_field_aggregate_test:410]: Structures 3 additional pool initialized successfully. 401s [test_stringfields.c:string_field_aggregate_test:422]: Structures 1/2 are equal as expected. 401s [test_stringfields.c:string_field_aggregate_test:430]: Structures 1/3 are different as expected. 401s [test_stringfields.c:string_field_aggregate_test:438]: Structures 2/3 are different as expected. 401s [test_stringfields.c:string_field_aggregate_test:446]: Structures 3/4 are different as expected. 401s [test_stringfields.c:string_field_aggregate_test:454]: Copying from structure 3 to structure 1 succeeded! 401s [test_stringfields.c:string_field_aggregate_test:463]: Structures 1/3 are equal as expected. 401s [test_stringfields.c:string_field_aggregate_test:470]: Structures 1/2 are different as expected. 401s [test_stringfields.c:string_field_aggregate_test:473]: Reset but don't free. 401s [test_stringfields.c:string_field_aggregate_test:484]: Structures 1/2 are the same (empty) as expected. 401s [test_stringfields.c:string_field_aggregate_test:492]: Structure 4 embedded pool is the current pool as expected. 401s [test_stringfields.c:string_field_aggregate_test:500]: Structure 4 embedded pool does not have a previous as expected. 401s END /main/utils/ - string_field_aggregate_test Time: <1ms Result: PASS 401s START /main/utils/ - string_field_test 401s [test_stringfields.c:string_field_test:79]: First things first. Let's see if we can actually allocate string fields 401s [test_stringfields.c:string_field_test:85]: All right! Successfully allocated! Now let's get down to business 401s [test_stringfields.c:string_field_test:89]: We're going to set some string fields and perform some checks 401s [test_stringfields.c:string_field_test:94]: First we're going to make sure that the strings are actually set to what we expect 401s [test_stringfields.c:string_field_test:100]: test_struct.string1 appears to be all clear. It has 'elephant' and that's what we expect 401s [test_stringfields.c:string_field_test:107]: test_struct.string2 appears to be all clear. It has 'hippopotamus' and that's what we expect 401s [test_stringfields.c:string_field_test:110]: Now let's make sure that our recorded capacities for these strings is what we expect 401s [test_stringfields.c:string_field_test:117]: string1 has the allocation area we expect: 9 401s [test_stringfields.c:string_field_test:125]: string2 has the allocation area we expect: 13 401s [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 401s [test_stringfields.c:string_field_test:137]: string1 successfully was changed to 'rhino' 401s [test_stringfields.c:string_field_test:144]: Shrinking string1 allowed it to stay in the same place in memory 401s [test_stringfields.c:string_field_test:151]: Shrinking string1 did not change its allocation area (This is a good thing) 401s [test_stringfields.c:string_field_test:154]: Next, let's increase it a little but not all the way to its original size 401s [test_stringfields.c:string_field_test:163]: string1 successfully was changed to 'mammoth' 401s [test_stringfields.c:string_field_test:170]: Expanding string1 allowed it to stay in the same place in memory 401s [test_stringfields.c:string_field_test:177]: Expanding string1 did not change its allocation area (This is a good thing) 401s [test_stringfields.c:string_field_test:180]: Cool, now let's bring it back to its original size and see what happens 401s [test_stringfields.c:string_field_test:188]: string1 successfully changed to 'elephant' 401s [test_stringfields.c:string_field_test:195]: Restoring string1 did not cause it to move (This is a good thing) 401s [test_stringfields.c:string_field_test:202]: The allocation amount for string1 is still holding steady 401s [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 401s [test_stringfields.c:string_field_test:214]: string2 successfully changed to 'hippopotamus face' 401s [test_stringfields.c:string_field_test:222]: The allocation amount successfully increased for string2 when it grew 401s [test_stringfields.c:string_field_test:229]: string2 stayed in place when it grew. Good job! 401s [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 401s [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' 401s [test_stringfields.c:string_field_test:248]: Good. Setting string1 to a long value caused it to change addresses 401s [test_stringfields.c:string_field_test:256]: The stored allocation size of string1 is what we expect 401s [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 401s [test_stringfields.c:string_field_test:281]: Three different pools are linked as expected. 401s [test_stringfields.c:string_field_test:289]: After removing a pool the remaining two are linked as expected. 401s END /main/utils/ - string_field_test Time: <1ms Result: PASS 401s START /main/uuid/ - uuid 401s [test_uuid.c:uuid:59]: Generate UUID direct to string, got 941fc622-660f-41b6-9d59-cf2c15636082 401s [test_uuid.c:uuid:90]: Second generated UUID converted to string, got 1ba507ae-c056-4143-8ba7-d4754fab1802 401s END /main/uuid/ - uuid Time: <1ms Result: PASS 401s START /main/vector/ - basic 401s END /main/vector/ - basic Time: <1ms Result: PASS 401s START /main/vector/ - basic_integer 401s END /main/vector/ - basic_integer Time: <1ms Result: PASS 401s START /main/vector/ - callbacks 401s END /main/vector/ - callbacks Time: <1ms Result: PASS 401s START /main/vector/ - locks 401s END /main/vector/ - locks Time: <1ms Result: PASS 401s START /main/voicemail_api/ - off_nominal_msg_playback 401s [test_voicemail_api.c:voicemail_api_off_nominal_msg_playback:1495]: Created message in test_vm_api_1234/Old with ID 1717420763-909401725 401s [test_voicemail_api.c:voicemail_api_off_nominal_msg_playback:1495]: Created message in test_vm_api_1234/INBOX with ID 1717420763-960311778 401s [test_voicemail_api.c:voicemail_api_off_nominal_msg_playback:1495]: Created message in test_vm_api_2345/INBOX with ID 1717420763-1500739833 401s [test_voicemail_api.c:voicemail_api_off_nominal_msg_playback:1495]: Created message in test_vm_api_2345/INBOX with ID 1717420763-719848782 401s [test_voicemail_api.c:voicemail_api_off_nominal_msg_playback:1504]: Playing back message from invalid mailbox 401s [test_voicemail_api.c:voicemail_api_off_nominal_msg_playback:1507]: Playing back message from NULL mailbox 401s [test_voicemail_api.c:voicemail_api_off_nominal_msg_playback:1510]: Playing back message from invalid context 401s [test_voicemail_api.c:voicemail_api_off_nominal_msg_playback:1513]: Playing back message from invalid folder 401s [test_voicemail_api.c:voicemail_api_off_nominal_msg_playback:1516]: Playing back message from NULL folder 401s [test_voicemail_api.c:voicemail_api_off_nominal_msg_playback:1519]: Playing back message with invalid message specifier 401s [test_voicemail_api.c:voicemail_api_off_nominal_msg_playback:1522]: Playing back message with NULL message specifier 401s END /main/voicemail_api/ - off_nominal_msg_playback Time: 9ms Result: PASS 401s START /main/voicemail_api/ - nominal_msg_playback 401s [test_voicemail_api.c:voicemail_api_nominal_msg_playback:1433]: Created message in test_vm_api_1234/Old with ID 1717420763-909401725 401s [test_voicemail_api.c:voicemail_api_nominal_msg_playback:1433]: Created message in test_vm_api_1234/INBOX with ID 1717420763-960311778 401s [test_voicemail_api.c:voicemail_api_nominal_msg_playback:1433]: Created message in test_vm_api_2345/INBOX with ID 1717420763-1500739833 401s [test_voicemail_api.c:voicemail_api_nominal_msg_playback:1433]: Created message in test_vm_api_2345/INBOX with ID 1717420763-719848782 401s [test_voicemail_api.c:voicemail_api_nominal_msg_playback:1445]: Playing back message from test_vm_api_1234 to mock channel 402s [test_voicemail_api.c:voicemail_api_nominal_msg_playback:1448]: Playing back message from test_vm_api_2345 to callback function 402s [test_voicemail_api.c:voicemail_api_nominal_msg_playback:1453]: Playing back message from test_vm_api_2345 to callback function with default context 402s END /main/voicemail_api/ - nominal_msg_playback Time: 453ms Result: PASS 402s START /main/voicemail_api/ - off_nominal_forward 402s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1355]: Created message in test_vm_api_1234/Old with ID 1717420764-909401725 402s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1355]: Created message in test_vm_api_1234/INBOX with ID 1717420764-960311778 402s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1355]: Created message in test_vm_api_2345/INBOX with ID 1717420764-1500739833 402s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1355]: Created message in test_vm_api_2345/INBOX with ID 1717420764-719848782 402s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1364]: Test forwarding from an invalid mailbox 402s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1367]: Test forwarding from a NULL mailbox 402s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1370]: Test forwarding from an invalid context 402s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1373]: Test forwarding from an invalid folder 402s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1376]: Test forwarding from a NULL folder 402s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1379]: Test forwarding to an invalid mailbox 402s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1382]: Test forwarding to a NULL mailbox 402s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1385]: Test forwarding to an invalid context 402s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1388]: Test forwarding to an invalid folder 402s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1392]: Test forwarding to a NULL folder 402s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1395]: Test forwarding when no messages are select 402s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1398]: Test forwarding a message that doesn't exist 402s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1402]: Test forwarding multiple messages, where some messages don't exist 402s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1405]: Test forwarding a message with an invalid size specifier 402s END /main/voicemail_api/ - off_nominal_forward Time: 9ms Result: PASS 402s START /main/voicemail_api/ - nominal_forward 402s [test_voicemail_api.c:voicemail_api_nominal_forward:1239]: Created message in test_vm_api_1234/Old with ID 1717420764-909401725 402s [test_voicemail_api.c:voicemail_api_nominal_forward:1239]: Created message in test_vm_api_1234/INBOX with ID 1717420764-960311778 402s [test_voicemail_api.c:voicemail_api_nominal_forward:1239]: Created message in test_vm_api_2345/INBOX with ID 1717420764-1500739833 402s [test_voicemail_api.c:voicemail_api_nominal_forward:1239]: Created message in test_vm_api_2345/INBOX with ID 1717420764-719848782 402s [test_voicemail_api.c:voicemail_api_nominal_forward:1246]: Test forwarding message 0 from test_vm_api_1234 INBOX to test_vm_api_2345 INBOX 402s [test_voicemail_api.c:voicemail_api_nominal_forward:1259]: Test forwarding message 0 from test_vm_api_1234 INBOX with default context to test_vm_api_2345 INBOX 402s [test_voicemail_api.c:voicemail_api_nominal_forward:1272]: Test forwarding message 0 from test_vm_api_1234 INBOX to test_vm_api_2345 INBOX with default context 402s [test_voicemail_api.c:voicemail_api_nominal_forward:1285]: Test forwarding message 0 from test_vm_api_1234 INBOX to test_vm_api_2345 INBOX, deleting original 402s [test_voicemail_api.c:voicemail_api_nominal_forward:1298]: Test forwarding 2 messages from test_vm_api_2345 INBOX to test_vm_api_1234 INBOX[test_voicemail_api.c:voicemail_api_nominal_forward:1311]: Test forwarding 2 messages from test_vm_api_2345 INBOX to test_vm_api_1234 Family, deleting original 402s END /main/voicemail_api/ - nominal_forward Time: 23ms Result: PASS 402s START /main/voicemail_api/ - off_nominal_remove 402s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1180]: Created message in test_vm_api_1234/Old with ID 1717420764-909401725 402s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1180]: Created message in test_vm_api_1234/INBOX with ID 1717420764-960311778 402s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1180]: Created message in test_vm_api_2345/INBOX with ID 1717420764-1500739833 402s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1180]: Created message in test_vm_api_2345/INBOX with ID 1717420764-719848782 402s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1186]: Test removing a single message with an invalid mailbox 402s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1189]: Test removing a single message with a NULL mailbox 402s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1192]: Test removing a single message with an invalid context 402s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1195]: Test removing a single message with an invalid folder 402s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1198]: Test removing a single message with a NULL folder 402s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1201]: Test removing a single message with an invalid message number 402s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1205]: Test removing multiple messages with a single invalid message number 402s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1209]: Test removing no messages with no message numbers 402s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1212]: Test removing multiple messages with an invalid size specifier 402s END /main/voicemail_api/ - off_nominal_remove Time: 8ms Result: PASS 402s START /main/voicemail_api/ - nominal_remove 402s [test_voicemail_api.c:voicemail_api_nominal_remove:1133]: Created message in test_vm_api_1234/Old with ID 1717420764-909401725 402s [test_voicemail_api.c:voicemail_api_nominal_remove:1133]: Created message in test_vm_api_1234/INBOX with ID 1717420764-960311778 402s [test_voicemail_api.c:voicemail_api_nominal_remove:1133]: Created message in test_vm_api_2345/INBOX with ID 1717420764-1500739833 402s [test_voicemail_api.c:voicemail_api_nominal_remove:1133]: Created message in test_vm_api_2345/INBOX with ID 1717420764-719848782 402s [test_voicemail_api.c:voicemail_api_nominal_remove:1141]: Test removing a single message from INBOX 402s [test_voicemail_api.c:voicemail_api_nominal_remove:1144]: Test removing a single message from Old 402s [test_voicemail_api.c:voicemail_api_nominal_remove:1147]: Test removing multiple messages from INBOX 402s END /main/voicemail_api/ - nominal_remove Time: 8ms Result: PASS 402s START /main/voicemail_api/ - off_nominal_move 402s [test_voicemail_api.c:voicemail_api_off_nominal_move:1061]: Created message in test_vm_api_1234/Old with ID 1717420764-909401725 402s [test_voicemail_api.c:voicemail_api_off_nominal_move:1061]: Created message in test_vm_api_1234/INBOX with ID 1717420764-960311778 402s [test_voicemail_api.c:voicemail_api_off_nominal_move:1061]: Created message in test_vm_api_2345/INBOX with ID 1717420764-1500739833 402s [test_voicemail_api.c:voicemail_api_off_nominal_move:1061]: Created message in test_vm_api_2345/INBOX with ID 1717420764-719848782 402s [test_voicemail_api.c:voicemail_api_off_nominal_move:1070]: Test move attempt for invalid mailbox test_vm_3456 402s [test_voicemail_api.c:voicemail_api_off_nominal_move:1075]: Test move attempt for invalid context test_vm_api_defunct 402s [test_voicemail_api.c:voicemail_api_off_nominal_move:1078]: Test move attempt to invalid folder 402s [test_voicemail_api.c:voicemail_api_off_nominal_move:1081]: Test move attempt from invalid folder 402s [test_voicemail_api.c:voicemail_api_off_nominal_move:1084]: Test move attempt to NULL folder 402s [test_voicemail_api.c:voicemail_api_off_nominal_move:1087]: Test move attempt from NULL folder 402s [test_voicemail_api.c:voicemail_api_off_nominal_move:1090]: Test move attempt with non-existent message number 402s [test_voicemail_api.c:voicemail_api_off_nominal_move:1094]: Test move attempt with invalid message number 402s [test_voicemail_api.c:voicemail_api_off_nominal_move:1098]: Test move attempt with 0 number of messages 402s [test_voicemail_api.c:voicemail_api_off_nominal_move:1102]: Test move attempt with invalid number of messages 402s [test_voicemail_api.c:voicemail_api_off_nominal_move:1105]: Test move attempt with non-existent multiple messages, where some messages exist 402s END /main/voicemail_api/ - off_nominal_move Time: 9ms Result: PASS 402s START /main/voicemail_api/ - nominal_move 402s [test_voicemail_api.c:voicemail_api_nominal_move:987]: Created message in test_vm_api_1234/Old with ID 1717420764-909401725 402s [test_voicemail_api.c:voicemail_api_nominal_move:987]: Created message in test_vm_api_1234/INBOX with ID 1717420764-960311778 402s [test_voicemail_api.c:voicemail_api_nominal_move:987]: Created message in test_vm_api_2345/INBOX with ID 1717420764-1500739833 402s [test_voicemail_api.c:voicemail_api_nominal_move:987]: Created message in test_vm_api_2345/INBOX with ID 1717420764-719848782 402s [test_voicemail_api.c:voicemail_api_nominal_move:994]: Test move of test_vm_api_1234 message from INBOX to Family 402s [test_voicemail_api.c:voicemail_api_nominal_move:997]: Test move of test_vm_api_1234 message from Old to Family 402s [test_voicemail_api.c:voicemail_api_nominal_move:1011]: Test move of test_vm_api_2345 messages from Inbox to Family 402s [test_voicemail_api.c:voicemail_api_nominal_move:1022]: Test move of test_vm_api_2345 message from Family to INBOX 402s END /main/voicemail_api/ - nominal_move Time: 13ms Result: PASS 402s START /main/voicemail_api/ - off_nominal_snapshot 402s [test_voicemail_api.c:voicemail_api_off_nominal_snapshot:947]: Created message in test_vm_api_1234/Old with ID 1717420764-909401725 402s [test_voicemail_api.c:voicemail_api_off_nominal_snapshot:947]: Created message in test_vm_api_1234/INBOX with ID 1717420764-960311778 402s [test_voicemail_api.c:voicemail_api_off_nominal_snapshot:947]: Created message in test_vm_api_2345/INBOX with ID 1717420764-1500739833 402s [test_voicemail_api.c:voicemail_api_off_nominal_snapshot:947]: Created message in test_vm_api_2345/INBOX with ID 1717420764-719848782 402s [test_voicemail_api.c:voicemail_api_off_nominal_snapshot:949]: Test access to non-existent mailbox test_vm_api_3456 402s [test_voicemail_api.c:voicemail_api_off_nominal_snapshot:952]: Test access to null mailbox 402s [test_voicemail_api.c:voicemail_api_off_nominal_snapshot:955]: Test access non-existent context test_vm_api_defunct 402s [test_voicemail_api.c:voicemail_api_off_nominal_snapshot:958]: Test non-existent folder test_vm_api_platypus 402s END /main/voicemail_api/ - off_nominal_snapshot Time: 7ms Result: PASS 402s START /main/voicemail_api/ - nominal_snapshot 402s [test_voicemail_api.c:voicemail_api_nominal_snapshot:856]: Created message in test_vm_api_1234/Old with ID 1717420764-909401725 402s [test_voicemail_api.c:voicemail_api_nominal_snapshot:856]: Created message in test_vm_api_1234/INBOX with ID 1717420764-960311778 402s [test_voicemail_api.c:voicemail_api_nominal_snapshot:856]: Created message in test_vm_api_2345/INBOX with ID 1717420764-1500739833 402s [test_voicemail_api.c:voicemail_api_nominal_snapshot:856]: Created message in test_vm_api_2345/INBOX with ID 1717420764-719848782 402s [test_voicemail_api.c:voicemail_api_nominal_snapshot:858]: Test retrieving message 1 from INBOX of test_vm_1234 402s [test_voicemail_api.c:voicemail_api_nominal_snapshot:861]: Found message 1717420764-960311778 in snapshot 402s [test_voicemail_api.c:voicemail_api_nominal_snapshot:864]: Test retrieving message 0 from Old of test_vm_1234 402s [test_voicemail_api.c:voicemail_api_nominal_snapshot:867]: Found message 1717420764-909401725 in snapshot 402s [test_voicemail_api.c:voicemail_api_nominal_snapshot:870]: Test retrieving message 0, 1 from Old and INBOX of test_vm_1234 ordered by time 402s [test_voicemail_api.c:voicemail_api_nominal_snapshot:873]: Found message 1717420764-909401725 in snapshot 402s [test_voicemail_api.c:voicemail_api_nominal_snapshot:874]: Found message 1717420764-960311778 in snapshot 402s [test_voicemail_api.c:voicemail_api_nominal_snapshot:877]: Test retrieving message 1, 0 from Old and INBOX of test_vm_1234 ordered by time desc 402s [test_voicemail_api.c:voicemail_api_nominal_snapshot:880]: Found message 1717420764-960311778 in snapshot 402s [test_voicemail_api.c:voicemail_api_nominal_snapshot:881]: Found message 1717420764-909401725 in snapshot 402s [test_voicemail_api.c:voicemail_api_nominal_snapshot:884]: Test retrieving message 0, 1 from Old and INBOX of test_vm_1234 ordered by id 402s [test_voicemail_api.c:voicemail_api_nominal_snapshot:887]: Found message 1717420764-960311778 in snapshot 402s [test_voicemail_api.c:voicemail_api_nominal_snapshot:888]: Found message 1717420764-909401725 in snapshot 402s [test_voicemail_api.c:voicemail_api_nominal_snapshot:891]: Test retrieving message 1, 0 from Old and INBOX of test_vm_1234 ordered by id desc 402s [test_voicemail_api.c:voicemail_api_nominal_snapshot:894]: Found message 1717420764-909401725 in snapshot 402s [test_voicemail_api.c:voicemail_api_nominal_snapshot:895]: Found message 1717420764-960311778 in snapshot 402s [test_voicemail_api.c:voicemail_api_nominal_snapshot:898]: Test retrieving message 0, 1 from all folders of test_vm_1234 ordered by id 402s [test_voicemail_api.c:voicemail_api_nominal_snapshot:901]: Found message 1717420764-909401725 in snapshot 402s [test_voicemail_api.c:voicemail_api_nominal_snapshot:902]: Found message 1717420764-960311778 in snapshot 402s [test_voicemail_api.c:voicemail_api_nominal_snapshot:905]: Test retrieving message 0, 1 from all folders of test_vm_1234 ordered by time 402s [test_voicemail_api.c:voicemail_api_nominal_snapshot:908]: Found message 1717420764-909401725 in snapshot 402s [test_voicemail_api.c:voicemail_api_nominal_snapshot:909]: Found message 1717420764-960311778 in snapshot 402s [test_voicemail_api.c:voicemail_api_nominal_snapshot:912]: Test retrieving message 0, 1 from all folders of test_vm_1234, default context ordered by time 402s [test_voicemail_api.c:voicemail_api_nominal_snapshot:915]: Found message 1717420764-909401725 in snapshot 402s [test_voicemail_api.c:voicemail_api_nominal_snapshot:916]: Found message 1717420764-960311778 in snapshot 402s END /main/voicemail_api/ - nominal_snapshot Time: 18ms Result: PASS 402s START /main/xml_escape/ - xml_escape_test 402s END /main/xml_escape/ - xml_escape_test Time: <1ms Result: PASS 402s START /mwi/ - explicit_publish 402s END /mwi/ - explicit_publish Time: 62ms Result: PASS 402s START /mwi/ - implicit_publish 402s END /mwi/ - implicit_publish Time: 60ms Result: PASS 402s START /res/adsi/ - adsi_loaded_test 402s END /res/adsi/ - adsi_loaded_test Time: <1ms Result: PASS 402s START /res/aeap/ - send_msg_handle_request 402s END /res/aeap/ - send_msg_handle_request Time: <1ms Result: PASS 402s START /res/aeap/ - send_msg_handle_response 402s END /res/aeap/ - send_msg_handle_response Time: <1ms Result: PASS 402s START /res/aeap/ - send_msg_handle_string 404s END /res/aeap/ - send_msg_handle_string Time: 1999ms Result: PASS 404s START /res/aeap/ - create_and_connect 404s END /res/aeap/ - create_and_connect Time: <1ms Result: PASS 404s START /res/aeap/speech/ - res_speech_aeap_test 404s END /res/aeap/speech/ - res_speech_aeap_test Time: <1ms Result: PASS 404s START /res/aeap/transaction/ - transaction_exec_timeout 404s END /res/aeap/transaction/ - transaction_exec_timeout Time: 99ms Result: PASS 404s START /res/aeap/transaction/ - transaction_exec 405s END /res/aeap/transaction/ - transaction_exec Time: 1000ms Result: PASS 405s START /res/aeap/transport/ - transport_create_invalid 405s END /res/aeap/transport/ - transport_create_invalid Time: <1ms Result: PASS 405s START /res/aeap/transport/ - transport_create 405s END /res/aeap/transport/ - transport_create Time: <1ms Result: PASS 405s START /res/aeap/transport/ - transport_connect 405s END /res/aeap/transport/ - transport_connect Time: <1ms Result: PASS 405s START /res/aeap/transport/ - transport_connect_fail 405s END /res/aeap/transport/ - transport_connect_fail Time: <1ms Result: PASS 405s START /res/aeap/transport/ - transport_binary 405s END /res/aeap/transport/ - transport_binary Time: <1ms Result: PASS 405s START /res/aeap/transport/ - transport_string 405s END /res/aeap/transport/ - transport_string Time: <1ms Result: PASS 405s START /res/agi/ - agi_loaded_test 405s END /res/agi/ - agi_loaded_test Time: <1ms Result: PASS 405s START /res/agi/ - null_agi_docs 405s END /res/agi/ - null_agi_docs Time: <1ms Result: PASS 405s START /res/ari/ - invoke_not_found 405s END /res/ari/ - invoke_not_found Time: <1ms Result: PASS 405s START /res/ari/ - invoke_bad_post 405s END /res/ari/ - invoke_bad_post Time: <1ms Result: PASS 405s START /res/ari/ - invoke_post 405s END /res/ari/ - invoke_post Time: <1ms Result: PASS 405s START /res/ari/ - invoke_delete 405s END /res/ari/ - invoke_delete Time: <1ms Result: PASS 405s START /res/ari/ - invoke_wildcard 405s END /res/ari/ - invoke_wildcard Time: <1ms Result: PASS 405s START /res/ari/ - invoke_get 405s END /res/ari/ - invoke_get Time: <1ms Result: PASS 405s START /res/ari/ - get_docs_hackerz 405s END /res/ari/ - get_docs_hackerz Time: <1ms Result: PASS 405s START /res/ari/ - get_docs_notfound 405s END /res/ari/ - get_docs_notfound Time: <1ms Result: PASS 405s START /res/ari/ - get_docs_nohost 405s END /res/ari/ - get_docs_nohost Time: <1ms Result: PASS 405s START /res/ari/ - get_docs 405s END /res/ari/ - get_docs Time: <1ms Result: PASS 405s START /res/crypto/ - crypto_loaded_test 405s END /res/crypto/ - crypto_loaded_test Time: <1ms Result: PASS 405s START /res/http_media_cache/ - retrieve_content_type 405s [test_http_media_cache.c:retrieve_content_type:255]: Condition failed: bucket_file != NULL 405s END /res/http_media_cache/ - retrieve_content_type Time: <1ms Result: FAIL 405s START /res/http_media_cache/ - retrieve_parsed_uri 405s [test_http_media_cache.c:retrieve_parsed_uri:289]: Condition failed: bucket_file != NULL 405s END /res/http_media_cache/ - retrieve_parsed_uri Time: <1ms Result: FAIL 405s START /res/http_media_cache/ - retrieve_cache_control_directives 405s [test_http_media_cache.c:retrieve_cache_control_directives:322]: Testing no-cache... 405s [test_http_media_cache.c:retrieve_cache_control_directives:325]: Condition failed: bucket_file != NULL 405s END /res/http_media_cache/ - retrieve_cache_control_directives Time: <1ms Result: FAIL 405s START /res/http_media_cache/ - retrieve_cache_control_age 405s [test_http_media_cache.c:retrieve_cache_control_age:406]: Testing max-age... 405s [test_http_media_cache.c:retrieve_cache_control_age:409]: Condition failed: bucket_file != NULL 405s END /res/http_media_cache/ - retrieve_cache_control_age Time: <1ms Result: FAIL 405s START /res/http_media_cache/ - retrieve_etag_expired 405s [test_http_media_cache.c:retrieve_etag_expired:510]: Condition failed: bucket_file != NULL 405s END /res/http_media_cache/ - retrieve_etag_expired Time: <1ms Result: FAIL 405s START /res/http_media_cache/ - retrieve_expires 405s [test_http_media_cache.c:retrieve_expires:551]: Condition failed: bucket_file != NULL 405s END /res/http_media_cache/ - retrieve_expires Time: <1ms Result: FAIL 405s START /res/http_media_cache/ - retrieve_etag 405s [test_http_media_cache.c:retrieve_etag:600]: Condition failed: bucket_file != NULL 405s END /res/http_media_cache/ - retrieve_etag Time: <1ms Result: FAIL 405s START /res/http_media_cache/ - retrieve_nominal 405s [test_http_media_cache.c:retrieve_nominal:639]: Condition failed: bucket_file != NULL 405s END /res/http_media_cache/ - retrieve_nominal Time: <1ms Result: FAIL 405s START /res/http_media_cache/ - create_nominal 405s [test_http_media_cache.c:create_nominal:673]: Condition failed: ast_bucket_file_temporary_create(bucket_file) == 0 405s END /res/http_media_cache/ - create_nominal Time: <1ms Result: FAIL 405s START /res/parking/ - dynamic_parking_variables 405s [parking/parking_tests.c:dynamic_parking_variables:756]: Creating expected configuration for dynamic parking lot 405s [parking/parking_tests.c:dynamic_parking_variables:775]: Creating template lot 405s [parking/parking_tests.c:dynamic_parking_variables:784]: Creating Alice channel to test dynamic parking lot creation. 405s [parking/parking_tests.c:dynamic_parking_variables:794]: Setting Dynamic Parking channel variables on Alice. 405s [parking/parking_tests.c:dynamic_parking_variables:802]: Generating dynamic parking lot based on Alice's channel variables. 405s [parking/parking_tests.c:dynamic_parking_variables:819]: Dynamic parking lot created successfully and matches expectations. Test passed. 405s END /res/parking/ - dynamic_parking_variables Time: <1ms Result: PASS 405s START /res/parking/ - extension_conflicts 405s [parking/parking_tests.c:extension_conflicts:597]: Creating the base lot. This should pass. 405s [parking/parking_tests.c:extension_conflicts:607]: Creating a test lot which will overlap. 405s [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. 405s [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. 405s [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. 405s [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. 405s END /res/parking/ - extension_conflicts Time: <1ms Result: PASS 405s START /res/parking/ - park_extensions 405s [parking/parking_tests.c:park_extensions:551]: Extensions for the test parking lot were verified. Cleaning up and verifying their removal. 405s [parking/parking_tests.c:park_extensions:565]: Extensions for the test parking lot verified as removed. Test completed successfully. 405s END /res/parking/ - park_extensions Time: <1ms Result: PASS 405s START /res/parking/ - park_retrieve 405s [parking/parking_tests.c:retrieve_call:405]: Creating test parking lot 'unit_tests_res_parking_test_lot' 406s [parking/parking_tests.c:retrieve_call:446]: Successfully retrieved parked user from the parking lot. Validating user data. 406s END /res/parking/ - park_retrieve Time: 1001ms Result: PASS 406s START /res/parking/ - park_channel 406s [parking/parking_tests.c:park_call:254]: Creating test parking lot 'unit_tests_res_parking_test_lot' 407s END /res/parking/ - park_channel Time: 1001ms Result: PASS 407s START /res/parking/ - create_lot 407s [parking/parking_tests.c:create_lot:206]: Creating test parking lot 'unit_tests_res_parking_test_lot' 407s [parking/parking_tests.c:create_lot:214]: Successfully created parking lot. Retrieving test parking lot from container. 407s [parking/parking_tests.c:create_lot:223]: Successfully retrieved parking lot. Removing test parking lot from container. 407s [parking/parking_tests.c:create_lot:229]: Parking lot was successfully removed from the container. Test complete. 407s END /res/parking/ - create_lot Time: <1ms Result: PASS 407s START /res/prometheus/ - bridge_to_string 407s [test_res_prometheus.c:bridge_to_string:744]: -> Retrieved: # HELP asterisk_channels_count Current channel count. 407s # TYPE asterisk_channels_count gauge 407s asterisk_channels_count{eid="fa:16:3e:98:a6:02"} 0 407s # HELP asterisk_calls_sum Total call count. 407s # TYPE asterisk_calls_sum counter 407s asterisk_calls_sum{eid="fa:16:3e:98:a6:02"} 0 407s # HELP asterisk_calls_count Current call count. 407s # TYPE asterisk_calls_count gauge 407s asterisk_calls_count{eid="fa:16:3e:98:a6:02"} 0 407s # HELP asterisk_endpoints_count Current endpoint count. 407s # TYPE asterisk_endpoints_count gauge 407s asterisk_endpoints_count{eid="fa:16:3e:98:a6:02"} 0 407s # HELP asterisk_bridges_count Current bridge count. 407s # TYPE asterisk_bridges_count gauge 407s asterisk_bridges_count{eid="fa:16:3e:98:a6:02"} 2 407s # HELP asterisk_bridges_channels_count Number of channels in the bridge. 407s # TYPE asterisk_bridges_channels_count gauge 407s asterisk_bridges_channels_count{eid="fa:16:3e:98:a6:02",id="972395ac-274a-4acc-88f2-92b1f63a99a2",tech="simple_bridge",subclass="basic",creator="",name=""} 0 407s asterisk_bridges_channels_count{eid="fa:16:3e:98:a6:02",id="972395ac-274a-4acc-88f2-92b1f63a99a2",tech="simple_bridge",subclass="basic",creator="",name=""} 0 407s 407s END /res/prometheus/ - bridge_to_string Time: <1ms Result: PASS 407s START /res/prometheus/ - config_general_core_metrics 407s [test_res_prometheus.c:config_general_core_metrics:680]: -> CURLing request... 407s [test_res_prometheus.c:config_general_core_metrics:688]: -> Retrieved: # HELP asterisk_channels_count Current channel count. 407s # TYPE asterisk_channels_count gauge 407s asterisk_channels_count{eid="fa:16:3e:98:a6:02"} 0 407s # HELP asterisk_calls_sum Total call count. 407s # TYPE asterisk_calls_sum counter 407s asterisk_calls_sum{eid="fa:16:3e:98:a6:02"} 0 407s # HELP asterisk_calls_count Current call count. 407s # TYPE asterisk_calls_count gauge 407s asterisk_calls_count{eid="fa:16:3e:98:a6:02"} 0 407s # HELP asterisk_endpoints_count Current endpoint count. 407s # TYPE asterisk_endpoints_count gauge 407s asterisk_endpoints_count{eid="fa:16:3e:98:a6:02"} 0 407s # HELP asterisk_bridges_count Current bridge count. 407s # TYPE asterisk_bridges_count gauge 407s asterisk_bridges_count{eid="fa:16:3e:98:a6:02"} 0 407s # HELP asterisk_core_properties Asterisk instance properties. The value of this will always be 1. 407s # TYPE asterisk_core_properties counter 407s asterisk_core_properties{eid="fa:16:3e:98:a6:02",version="20.6.0~dfsg+~cs6.13.40431414-2build5",build_options="OPTIONAL_API, TEST_FRAMEWORK",build_date="2024-04-15 00:13:12 UTC",build_os="Linux",build_kernel="unknown",build_host="buildd.debian.org"} 1 407s # HELP asterisk_core_uptime_seconds Asterisk instance uptime in seconds. 407s # TYPE asterisk_core_uptime_seconds counter 407s asterisk_core_uptime_seconds{eid="fa:16:3e:98:a6:02"} 182 407s # HELP asterisk_core_last_reload_seconds Time since last Asterisk reload in seconds. 407s # TYPE asterisk_core_last_reload_seconds counter 407s asterisk_core_last_reload_seconds{eid="fa:16:3e:98:a6:02"} 182 407s # HELP asterisk_core_scrape_time_ms Total time taken to collect metrics, in milliseconds 407s # TYPE asterisk_core_scrape_time_ms counter 407s asterisk_core_scrape_time_ms{eid="fa:16:3e:98:a6:02"} 0 407s 407s [test_res_prometheus.c:config_general_core_metrics:690]: -> Checking for core properties 407s [test_res_prometheus.c:config_general_core_metrics:693]: -> Checking for uptime 407s [test_res_prometheus.c:config_general_core_metrics:696]: -> Checking for last reload 407s [test_res_prometheus.c:config_general_core_metrics:699]: -> Checking for scrape time 407s END /res/prometheus/ - config_general_core_metrics Time: 2ms Result: PASS 407s START /res/prometheus/ - config_general_basic_auth 407s [test_res_prometheus.c:config_general_basic_auth:555]: Testing without auth credentials 407s [test_res_prometheus.c:config_general_basic_auth:556]: -> CURLing request... 407s [test_res_prometheus.c:config_general_basic_auth:563]: -> CURL returned 401 407s [test_res_prometheus.c:config_general_basic_auth:566]: Testing with invalid auth credentials 407s [test_res_prometheus.c:config_general_basic_auth:567]: -> CURLing request... 407s [test_res_prometheus.c:config_general_basic_auth:576]: -> CURL returned 401 407s [test_res_prometheus.c:config_general_basic_auth:579]: Testing with valid auth credentials 407s [test_res_prometheus.c:config_general_basic_auth:580]: -> CURLing request... 407s [test_res_prometheus.c:config_general_basic_auth:588]: -> CURL returned 200 407s END /res/prometheus/ - config_general_basic_auth Time: <1ms Result: PASS 407s START /res/prometheus/ - config_general_enabled 407s [test_res_prometheus.c:config_general_enabled:628]: -> CURLing request... 407s [test_res_prometheus.c:config_general_enabled:635]: -> CURL returned 503 407s END /res/prometheus/ - config_general_enabled Time: <1ms Result: PASS 407s START /res/prometheus/ - gauge_create 407s END /res/prometheus/ - gauge_create Time: <1ms Result: PASS 407s START /res/prometheus/ - gauge_to_string 407s END /res/prometheus/ - gauge_to_string Time: <1ms Result: PASS 407s START /res/prometheus/ - counter_create 407s END /res/prometheus/ - counter_create Time: <1ms Result: PASS 407s START /res/prometheus/ - counter_to_string 407s END /res/prometheus/ - counter_to_string Time: <1ms Result: PASS 407s START /res/prometheus/ - metric_register 407s [test_res_prometheus.c:metric_register:291]: Testing nominal registration 407s [test_res_prometheus.c:metric_register:292]: -> Static metric 407s [test_res_prometheus.c:metric_register:294]: -> Malloc'd metric 407s [test_res_prometheus.c:metric_register:300]: Testing nominal registration of child metrics 407s [test_res_prometheus.c:metric_register:315]: Testing name collisions 407s [test_res_prometheus.c:metric_register:322]: Testing label collisions 407s [test_res_prometheus.c:metric_register:331]: Testing removal of metrics 407s END /res/prometheus/ - metric_register Time: <1ms Result: PASS 407s START /res/prometheus/ - metric_callback_register 407s [test_res_prometheus.c:metric_callback_register:241]: -> CURLing request... 407s [test_res_prometheus.c:metric_callback_register:250]: -> Retrieved: # HELP asterisk_channels_count Current channel count. 407s # TYPE asterisk_channels_count gauge 407s asterisk_channels_count{eid="fa:16:3e:98:a6:02"} 0 407s # HELP asterisk_calls_sum Total call count. 407s # TYPE asterisk_calls_sum counter 407s asterisk_calls_sum{eid="fa:16:3e:98:a6:02"} 0 407s # HELP asterisk_calls_count Current call count. 407s # TYPE asterisk_calls_count gauge 407s asterisk_calls_count{eid="fa:16:3e:98:a6:02"} 0 407s # HELP asterisk_endpoints_count Current endpoint count. 407s # TYPE asterisk_endpoints_count gauge 407s asterisk_endpoints_count{eid="fa:16:3e:98:a6:02"} 0 407s # HELP asterisk_bridges_count Current bridge count. 407s # TYPE asterisk_bridges_count gauge 407s asterisk_bridges_count{eid="fa:16:3e:98:a6:02"} 0 407s # HELP test_counter A test counter 407s # TYPE test_counter counter 407s test_counter 0 407s 407s END /res/prometheus/ - metric_callback_register Time: <1ms Result: PASS 407s START /res/prometheus/ - metric_values 407s [test_res_prometheus.c:metric_values:166]: -> CURLing request... 407s [test_res_prometheus.c:metric_values:176]: -> Retrieved: # HELP asterisk_channels_count Current channel count. 407s # TYPE asterisk_channels_count gauge 407s asterisk_channels_count{eid="fa:16:3e:98:a6:02"} 0 407s # HELP asterisk_calls_sum Total call count. 407s # TYPE asterisk_calls_sum counter 407s asterisk_calls_sum{eid="fa:16:3e:98:a6:02"} 0 407s # HELP asterisk_calls_count Current call count. 407s # TYPE asterisk_calls_count gauge 407s asterisk_calls_count{eid="fa:16:3e:98:a6:02"} 0 407s # HELP asterisk_endpoints_count Current endpoint count. 407s # TYPE asterisk_endpoints_count gauge 407s asterisk_endpoints_count{eid="fa:16:3e:98:a6:02"} 0 407s # HELP asterisk_bridges_count Current bridge count. 407s # TYPE asterisk_bridges_count gauge 407s asterisk_bridges_count{eid="fa:16:3e:98:a6:02"} 0 407s # HELP test_counter_one A test counter 407s # TYPE test_counter_one counter 407s test_counter_one 1 407s # HELP test_counter_two A test counter 407s # TYPE test_counter_two counter 407s test_counter_two 2 407s 407s END /res/prometheus/ - metric_values Time: <1ms Result: PASS 407s START /res/res_crypto/ - crypto_aes_decrypt 407s [test_crypto.c:crypto_aes_decrypt:607]: Executing AES-ECB decryption test 407s END /res/res_crypto/ - crypto_aes_decrypt Time: 16ms Result: PASS 407s START /res/res_crypto/ - crypto_aes_encrypt 407s [test_crypto.c:crypto_aes_encrypt:531]: Executing AES-ECB encryption test 407s END /res/res_crypto/ - crypto_aes_encrypt Time: 10ms Result: PASS 407s START /res/res_crypto/ - crypto_verify 407s [test_crypto.c:crypto_verify:425]: Executing RSA signature verification test 407s [test_crypto.c:crypto_verify:456]: Couldn't read key: rsa_key1 407s END /res/res_crypto/ - crypto_verify Time: <1ms Result: FAIL 407s START /res/res_crypto/ - crypto_sign 407s [test_crypto.c:crypto_sign:306]: Executing RSA signing test 407s [test_crypto.c:crypto_sign:341]: Couldn't read key: rsa_key1 407s END /res/res_crypto/ - crypto_sign Time: <1ms Result: FAIL 407s START /res/res_crypto/ - crypto_decrypt_pub_key 407s [test_crypto.c:crypto_rsa_decrypt:203]: Executing RSA decryption test 407s [test_crypto.c:crypto_rsa_decrypt:231]: Couldn't read key: rsa_key1 407s END /res/res_crypto/ - crypto_decrypt_pub_key Time: <1ms Result: FAIL 407s START /res/res_crypto/ - crypto_rsa_encrypt 407s [test_crypto.c:crypto_rsa_encrypt:107]: Executing RSA encryption test 407s [test_crypto.c:crypto_rsa_encrypt:138]: Couldn't read key: rsa_key1 407s END /res/res_crypto/ - crypto_rsa_encrypt Time: <1ms Result: FAIL 407s START /res/res_pjproject/ - ast_sockaddr_from_pj_sockaddr_test 407s END /res/res_pjproject/ - ast_sockaddr_from_pj_sockaddr_test Time: <1ms Result: PASS 407s START /res/res_pjproject/ - ast_sockaddr_to_pj_sockaddr_test 407s END /res/res_pjproject/ - ast_sockaddr_to_pj_sockaddr_test Time: <1ms Result: PASS 407s START /res/res_pjsip/ - xml_sanitization_exceeds_buffer 407s END /res/res_pjsip/ - xml_sanitization_exceeds_buffer Time: <1ms Result: PASS 407s START /res/res_pjsip/ - xml_sanitization_end_null 407s END /res/res_pjsip/ - xml_sanitization_end_null Time: <1ms Result: PASS 407s START /res/res_pjsip/scheduler/ - scheduler_policy 407s [test_res_pjsip_scheduler.c:scheduler_policy:355]: This test will take about 4.5 seconds 412s END /res/res_pjsip/scheduler/ - scheduler_policy Time: 4499ms Result: PASS 412s START /res/res_pjsip/scheduler/ - scheduler_cancel 412s [test_res_pjsip_scheduler.c:scheduler_cancel:301]: This test will take about 1.5 seconds 413s END /res/res_pjsip/scheduler/ - scheduler_cancel Time: 1500ms Result: PASS 413s START /res/res_pjsip/scheduler/ - scheduler_cleanup 413s [test_res_pjsip_scheduler.c:scheduler_cleanup:250]: This test will take about 1.6 seconds 415s END /res/res_pjsip/scheduler/ - scheduler_cleanup Time: 1600ms Result: PASS 415s START /res/res_pjsip/scheduler/ - unserialized_scheduler 415s [test_res_pjsip_scheduler.c:scheduler:136]: This test will take about 3.0 seconds 419s [test_res_pjsip_scheduler.c:scheduler:167]: Condition failed: test_data1->tid != test_data2->tid 419s END /res/res_pjsip/scheduler/ - unserialized_scheduler Time: 3999ms Result: FAIL 419s START /res/res_pjsip/scheduler/ - serialized_scheduler 419s [test_res_pjsip_scheduler.c:scheduler:131]: This test will take about 4.0 seconds 423s END /res/res_pjsip/scheduler/ - serialized_scheduler Time: 3999ms Result: PASS 423s START /res/res_pjsip_pubsub/ - bad_event 423s END /res/res_pjsip_pubsub/ - bad_event Time: <1ms Result: PASS 423s START /res/res_pjsip_pubsub/ - loop 423s END /res/res_pjsip_pubsub/ - loop Time: <1ms Result: PASS 423s START /res/res_pjsip_pubsub/ - duplicate_resource 423s END /res/res_pjsip_pubsub/ - duplicate_resource Time: <1ms Result: PASS 423s START /res/res_pjsip_pubsub/ - bad_branch 423s END /res/res_pjsip_pubsub/ - bad_branch Time: <1ms Result: PASS 423s START /res/res_pjsip_pubsub/ - bad_resource 423s END /res/res_pjsip_pubsub/ - bad_resource Time: <1ms Result: PASS 423s START /res/res_pjsip_pubsub/ - complex_resource_tree 423s END /res/res_pjsip_pubsub/ - complex_resource_tree Time: <1ms Result: PASS 423s START /res/res_pjsip_pubsub/ - resource_tree 423s END /res/res_pjsip_pubsub/ - resource_tree Time: <1ms Result: PASS 423s START /res/res_pjsip_session/ - merge_refresh_topologies 423s [res_pjsip_session.c:test_resolve_refresh_media_states:5894]: Test 1 passed 423s [res_pjsip_session.c:test_resolve_refresh_media_states:5914]: Test 2 passed 423s [res_pjsip_session.c:test_resolve_refresh_media_states:5938]: Test 3 passed 423s [res_pjsip_session.c:test_resolve_refresh_media_states:5957]: Test 4 passed 423s [res_pjsip_session.c:test_resolve_refresh_media_states:5975]: Test 5 passed 423s [res_pjsip_session.c:test_resolve_refresh_media_states:5996]: Test 6 passed 423s [res_pjsip_session.c:test_resolve_refresh_media_states:6022]: Test 7 passed 423s [res_pjsip_session.c:test_resolve_refresh_media_states:6043]: Test 8 passed 423s [res_pjsip_session.c:test_resolve_refresh_media_states:6063]: Test 9 passed 423s [res_pjsip_session.c:test_resolve_refresh_media_states:6083]: Test 10 passed 423s [res_pjsip_session.c:test_resolve_refresh_media_states:6106]: Test 11 passed 423s [res_pjsip_session.c:test_resolve_refresh_media_states:6131]: Test 12 passed 423s [res_pjsip_session.c:test_resolve_refresh_media_states:6165]: Test 13 passed 423s [res_pjsip_session.c:test_resolve_refresh_media_states:6189]: Test 14 passed 423s [res_pjsip_session.c:test_resolve_refresh_media_states:6213]: Test 15 passed 423s END /res/res_pjsip_session/ - merge_refresh_topologies Time: <1ms Result: PASS 423s START /res/res_pjsip_session/caps/ - low_level 423s [test_res_pjsip_session_caps.c:low_level:134]: Testing incoming expected pass 423s [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) 423s [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) 423s [test_res_pjsip_session_caps.c:test_create_joint:60]: Testing local: (slin), remote: (all), pref: (local ), outgoing: (no ), expected: (slin) expected result: (PASS) 423s [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) 423s [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) 423s [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) 423s [test_res_pjsip_session_caps.c:low_level:142]: Testing incoming expected fail 423s [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) 423s [test_res_pjsip_session_caps.c:test_create_joint:102]: Expected Failure: Expected: () Actual: (nothing) 423s [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) 423s [test_res_pjsip_session_caps.c:test_create_joint:81]: Expected Failure: Invalid preference string incoming/outgoing combination. 423s [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) 423s [test_res_pjsip_session_caps.c:test_create_joint:81]: Expected Failure: Invalid preference string incoming/outgoing combination. 423s [test_res_pjsip_session_caps.c:low_level:147]: Testing outgoing expected pass 423s [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) 423s [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) 423s [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) 423s [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) 423s [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) 423s [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) 423s [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) 423s END /res/res_pjsip_session/caps/ - low_level Time: 2ms Result: PASS 423s START /res/res_resolver_unbound/ - resolve_srv 423s END /res/res_resolver_unbound/ - resolve_srv Time: 2ms Result: PASS 423s START /res/res_resolver_unbound/ - resolve_naptr 423s END /res/res_resolver_unbound/ - resolve_naptr Time: <1ms Result: PASS 423s START /res/res_resolver_unbound/ - resolve_cancel_off_nominal 423s END /res/res_resolver_unbound/ - resolve_cancel_off_nominal Time: 4ms Result: PASS 423s START /res/res_resolver_unbound/ - resolve_async_off_nominal 423s [res_resolver_unbound.c:off_nominal_async_run:995]: Performing DNS query 'duck.feathers', type 1 423s [res_resolver_unbound.c:off_nominal_async_run:995]: Performing DNS query 'goose.feathers', type 28 423s [res_resolver_unbound.c:off_nominal_async_run:995]: Performing DNS query 'goose.feathers', type 1 423s END /res/res_resolver_unbound/ - resolve_async_off_nominal Time: <1ms Result: PASS 423s START /res/res_resolver_unbound/ - resolve_sync_off_nominal 423s END /res/res_resolver_unbound/ - resolve_sync_off_nominal Time: <1ms Result: PASS 423s START /res/res_resolver_unbound/ - resolve_async 423s [res_resolver_unbound.c:nominal_async_run:713]: Performing DNS query 'goose.feathers', type 1 423s [res_resolver_unbound.c:nominal_async_run:713]: Performing DNS query 'goose.feathers', type 28 423s [res_resolver_unbound.c:nominal_async_run:713]: Performing DNS query 'duck.feathers', type 1 423s END /res/res_resolver_unbound/ - resolve_async Time: <1ms Result: PASS 423s START /res/res_resolver_unbound/ - resolve_sync 423s [res_resolver_unbound.c:nominal_sync_run:563]: Performing DNS query 'goose.feathers', type 1 423s [res_resolver_unbound.c:nominal_sync_run:563]: Performing DNS query 'goose.feathers', type 28 423s [res_resolver_unbound.c:nominal_sync_run:563]: Performing DNS query 'duck.feathers', type 1 423s END /res/res_resolver_unbound/ - resolve_sync Time: <1ms Result: PASS 423s START /res/res_rtp/ - fir_nominal 423s END /res/res_rtp/ - fir_nominal Time: <1ms Result: PASS 423s START /res/res_rtp/ - sr_rr_nominal 423s END /res/res_rtp/ - sr_rr_nominal Time: <1ms Result: PASS 423s START /res/res_rtp/ - remb_nominal 423s END /res/res_rtp/ - remb_nominal Time: <1ms Result: PASS 423s START /res/res_rtp/ - lost_packet_stats_nominal 423s END /res/res_rtp/ - lost_packet_stats_nominal Time: <1ms Result: PASS 423s START /res/res_rtp/ - nack_overflow 423s END /res/res_rtp/ - nack_overflow Time: <1ms Result: PASS 423s START /res/res_rtp/ - nack_nominal 423s END /res/res_rtp/ - nack_nominal Time: <1ms Result: PASS 423s START /res/res_rtp/ - nack_no_packet_loss 423s END /res/res_rtp/ - nack_no_packet_loss Time: <1ms Result: PASS 423s START /res/res_sorcery_memory_cache/ - full_backend_cache_stale 438s END /res/res_sorcery_memory_cache/ - full_backend_cache_stale Time: 15000ms Result: PASS 438s START /res/res_sorcery_memory_cache/ - full_backend_cache_expiration 443s END /res/res_sorcery_memory_cache/ - full_backend_cache_expiration Time: 5000ms Result: PASS 443s START /res/res_sorcery_memory_cache/ - expiration 448s END /res/res_sorcery_memory_cache/ - expiration Time: 4999ms Result: PASS 448s START /res/res_sorcery_memory_cache/ - maximum_objects 448s END /res/res_sorcery_memory_cache/ - maximum_objects Time: 4ms Result: PASS 448s START /res/res_sorcery_memory_cache/ - delete 448s END /res/res_sorcery_memory_cache/ - delete Time: <1ms Result: PASS 448s START /res/res_sorcery_memory_cache/ - create 448s END /res/res_sorcery_memory_cache/ - create Time: <1ms Result: PASS 448s START /res/res_sorcery_memory_cache/ - create 448s END /res/res_sorcery_memory_cache/ - create Time: <1ms Result: PASS 448s START /res/res_sorcery_memory_cache/ - open_with_invalid_options 448s END /res/res_sorcery_memory_cache/ - open_with_invalid_options Time: <1ms Result: PASS 448s START /res/res_sorcery_memory_cache/ - open_with_valid_options 448s END /res/res_sorcery_memory_cache/ - open_with_valid_options Time: <1ms Result: PASS 448s START /res/res_sorcery_memory_cache/ - stale 448s [res_sorcery_memory_cache.c:stale:3189]: Begininning iteration 0 453s [res_sorcery_memory_cache.c:stale:3189]: Begininning iteration 1 458s [res_sorcery_memory_cache.c:stale:3189]: Begininning iteration 2 463s END /res/res_sorcery_memory_cache/ - stale Time: 15000ms Result: PASS 463s START /res/res_sorcery_memory_cache/thrash/ - high_object_count_without_expiration 466s END /res/res_sorcery_memory_cache/thrash/ - high_object_count_without_expiration Time: 3048ms Result: PASS 466s START /res/res_sorcery_memory_cache/thrash/ - conflicting_expire_and_stale 472s END /res/res_sorcery_memory_cache/thrash/ - conflicting_expire_and_stale Time: 6021ms Result: PASS 472s START /res/res_sorcery_memory_cache/thrash/ - unique_objects_exceeding_maximum_with_expire_and_stale 478s END /res/res_sorcery_memory_cache/thrash/ - unique_objects_exceeding_maximum_with_expire_and_stale Time: 6019ms Result: PASS 478s START /res/res_sorcery_memory_cache/thrash/ - unique_objects_exceeding_maximum 481s END /res/res_sorcery_memory_cache/thrash/ - unique_objects_exceeding_maximum Time: 3007ms Result: PASS 481s START /res/res_sorcery_memory_cache/thrash/ - low_unique_object_count_high_concurrent_updates 484s END /res/res_sorcery_memory_cache/thrash/ - low_unique_object_count_high_concurrent_updates Time: 3019ms Result: PASS 484s START /res/res_sorcery_memory_cache/thrash/ - low_unique_object_count_immediately_expire 487s END /res/res_sorcery_memory_cache/thrash/ - low_unique_object_count_immediately_expire Time: 3008ms Result: PASS 487s START /res/res_sorcery_memory_cache/thrash/ - low_unique_object_count_immediately_stale 490s END /res/res_sorcery_memory_cache/thrash/ - low_unique_object_count_immediately_stale Time: 3044ms Result: PASS 490s START /res/res_stir_shaken/ - stir_shaken_verify 490s END /res/res_stir_shaken/ - stir_shaken_verify Time: 2ms Result: PASS 490s START /res/res_stir_shaken/ - stir_shaken_sign 490s END /res/res_stir_shaken/ - stir_shaken_sign Time: 2ms Result: PASS 490s START /res/sorcery_astdb/ - object_delete_uncreated 490s END /res/sorcery_astdb/ - object_delete_uncreated Time: 2ms Result: PASS 490s START /res/sorcery_astdb/ - object_delete 490s END /res/sorcery_astdb/ - object_delete Time: <1ms Result: PASS 490s START /res/sorcery_astdb/ - object_update_uncreated 490s END /res/sorcery_astdb/ - object_update_uncreated Time: <1ms Result: PASS 490s START /res/sorcery_astdb/ - object_update 490s END /res/sorcery_astdb/ - object_update Time: <1ms Result: PASS 490s START /res/sorcery_astdb/ - object_retrieve_regex 490s END /res/sorcery_astdb/ - object_retrieve_regex Time: <1ms Result: PASS 490s START /res/sorcery_astdb/ - object_retrieve_multiple_field 490s END /res/sorcery_astdb/ - object_retrieve_multiple_field Time: <1ms Result: PASS 490s START /res/sorcery_astdb/ - object_retrieve_multiple_all 490s END /res/sorcery_astdb/ - object_retrieve_multiple_all Time: <1ms Result: PASS 490s START /res/sorcery_astdb/ - object_retrieve_field 490s END /res/sorcery_astdb/ - object_retrieve_field Time: <1ms Result: PASS 490s START /res/sorcery_astdb/ - object_retrieve_id 490s END /res/sorcery_astdb/ - object_retrieve_id Time: <1ms Result: PASS 490s START /res/sorcery_astdb/ - object_create 490s END /res/sorcery_astdb/ - object_create Time: <1ms Result: PASS 490s START /res/sorcery_realtime/ - object_filter 490s END /res/sorcery_realtime/ - object_filter Time: <1ms Result: PASS 490s START /res/sorcery_realtime/ - object_allocate_on_retrieval 490s END /res/sorcery_realtime/ - object_allocate_on_retrieval Time: <1ms Result: PASS 490s START /res/sorcery_realtime/ - object_delete_uncreated 490s END /res/sorcery_realtime/ - object_delete_uncreated Time: <1ms Result: PASS 490s START /res/sorcery_realtime/ - object_delete 490s END /res/sorcery_realtime/ - object_delete Time: <1ms Result: PASS 490s START /res/sorcery_realtime/ - object_update 490s END /res/sorcery_realtime/ - object_update Time: <1ms Result: PASS 490s START /res/sorcery_realtime/ - object_retrieve_regex_nofetch 490s END /res/sorcery_realtime/ - object_retrieve_regex_nofetch Time: <1ms Result: PASS 490s START /res/sorcery_realtime/ - object_retrieve_regex 490s END /res/sorcery_realtime/ - object_retrieve_regex Time: <1ms Result: PASS 490s START /res/sorcery_realtime/ - object_retrieve_multiple_field 490s END /res/sorcery_realtime/ - object_retrieve_multiple_field Time: <1ms Result: PASS 490s START /res/sorcery_realtime/ - object_retrieve_multiple_all_nofetch 490s END /res/sorcery_realtime/ - object_retrieve_multiple_all_nofetch Time: <1ms Result: PASS 490s START /res/sorcery_realtime/ - object_retrieve_multiple_all 490s END /res/sorcery_realtime/ - object_retrieve_multiple_all Time: <1ms Result: PASS 490s START /res/sorcery_realtime/ - object_retrieve_field 490s END /res/sorcery_realtime/ - object_retrieve_field Time: <1ms Result: PASS 490s START /res/sorcery_realtime/ - object_retrieve_id 490s END /res/sorcery_realtime/ - object_retrieve_id Time: <1ms Result: PASS 490s START /res/sorcery_realtime/ - object_create 490s END /res/sorcery_realtime/ - object_create Time: <1ms Result: PASS 490s START /res/websocket/ - websocket_client_multiple_protocols 490s END /res/websocket/ - websocket_client_multiple_protocols Time: <1ms Result: PASS 490s START /res/websocket/ - websocket_client_unsupported_protocol 490s END /res/websocket/ - websocket_client_unsupported_protocol Time: <1ms Result: PASS 490s START /res/websocket/ - websocket_client_bad_url 490s END /res/websocket/ - websocket_client_bad_url Time: 83ms Result: PASS 490s START /stasis/channels/ - channel_redirect_snapshot_json 490s END /stasis/channels/ - channel_redirect_snapshot_json Time: <1ms Result: PASS 490s START /stasis/channels/ - channel_snapshot_json 490s END /stasis/channels/ - channel_snapshot_json Time: <1ms Result: PASS 490s START /stasis/channels/ - multi_channel_blob_snapshots 490s END /stasis/channels/ - multi_channel_blob_snapshots Time: <1ms Result: PASS 490s START /stasis/channels/ - multi_channel_blob_create 490s END /stasis/channels/ - multi_channel_blob_create Time: <1ms Result: PASS 490s START /stasis/channels/ - null_blob 490s END /stasis/channels/ - null_blob Time: <1ms Result: PASS 490s START /stasis/channels/ - channel_blob_create 490s END /stasis/channels/ - channel_blob_create Time: <1ms Result: PASS 490s START /stasis/core/ - caching_dtor_order 490s END /stasis/core/ - caching_dtor_order Time: <1ms Result: PASS 490s START /stasis/core/ - dtor_order 490s END /stasis/core/ - dtor_order Time: <1ms Result: PASS 490s START /stasis/core/ - to_ami 490s END /stasis/core/ - to_ami Time: <1ms Result: PASS 490s START /stasis/core/ - no_to_ami 490s END /stasis/core/ - no_to_ami Time: <1ms Result: PASS 490s START /stasis/core/ - to_json 490s END /stasis/core/ - to_json Time: <1ms Result: PASS 490s START /stasis/core/ - no_to_json 490s END /stasis/core/ - no_to_json Time: <1ms Result: PASS 490s START /stasis/core/ - subscription_interleaving 490s END /stasis/core/ - subscription_interleaving Time: <1ms Result: PASS 490s START /stasis/core/ - interleaving 490s END /stasis/core/ - interleaving Time: <1ms Result: PASS 490s START /stasis/core/ - router_cache_updates 490s END /stasis/core/ - router_cache_updates Time: 100ms Result: PASS 490s START /stasis/core/ - router_pool 490s END /stasis/core/ - router_pool Time: <1ms Result: PASS 490s START /stasis/core/ - router 490s END /stasis/core/ - router Time: <1ms Result: PASS 490s START /stasis/core/ - cache_eid_aggregate 490s END /stasis/core/ - cache_eid_aggregate Time: <1ms Result: PASS 490s START /stasis/core/ - cache_dump 490s END /stasis/core/ - cache_dump Time: <1ms Result: PASS 490s START /stasis/core/ - cache 490s END /stasis/core/ - cache Time: <1ms Result: PASS 490s START /stasis/core/ - cache_filter 490s END /stasis/core/ - cache_filter Time: 100ms Result: PASS 490s START /stasis/core/ - forward 490s END /stasis/core/ - forward Time: <1ms Result: PASS 490s START /stasis/core/ - unsubscribe_stops_messages 490s END /stasis/core/ - unsubscribe_stops_messages Time: 100ms Result: PASS 490s START /stasis/core/ - publish_pool 490s END /stasis/core/ - publish_pool Time: <1ms Result: PASS 490s START /stasis/core/ - publish_sync 490s END /stasis/core/ - publish_sync Time: <1ms Result: PASS 490s START /stasis/core/ - publish 490s END /stasis/core/ - publish Time: <1ms Result: PASS 490s START /stasis/core/ - subscription_pool_messages 490s END /stasis/core/ - subscription_pool_messages Time: <1ms Result: PASS 490s START /stasis/core/ - subscription_messages 490s END /stasis/core/ - subscription_messages Time: <1ms Result: PASS 490s START /stasis/core/ - message 490s END /stasis/core/ - message Time: <1ms Result: PASS 490s START /stasis/core/ - message_type 490s END /stasis/core/ - message_type Time: <1ms Result: PASS 490s START /stasis/core/filtering/ - combo_filters 490s [test_stasis.c:dump_consumer:2198]: Messages received: 7 Final? yes 490s [test_stasis.c:dump_consumer:2202]: Message type received: stasis_subscription_change_type Subscribe 490s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageType1 Pass 490s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageType2 Pass 490s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageAMI Pass 490s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageAMIEVENT Pass 490s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageJSON Pass 490s [test_stasis.c:dump_consumer:2202]: Message type received: stasis_subscription_change_type Unsubscribe 490s END /stasis/core/filtering/ - combo_filters Time: <1ms Result: PASS 490s START /stasis/core/filtering/ - formatter_filters 490s [test_stasis.c:dump_consumer:2198]: Messages received: 7 Final? yes 490s [test_stasis.c:dump_consumer:2202]: Message type received: stasis_subscription_change_type Subscribe 490s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageAMI Pass 490s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageJSON Pass 490s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageAMIEVENT Pass 490s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageAMIEVENT Pass2 490s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageEVENT Pass 490s [test_stasis.c:dump_consumer:2202]: Message type received: stasis_subscription_change_type Unsubscribe 490s END /stasis/core/filtering/ - formatter_filters Time: <1ms Result: PASS 490s START /stasis/core/filtering/ - type_filters 490s [test_stasis.c:dump_consumer:2198]: Messages received: 5 Final? yes 490s [test_stasis.c:dump_consumer:2202]: Message type received: stasis_subscription_change_type Subscribe 490s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageType1 Pass 490s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageType2 Pass 490s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageType2 Pass2 490s [test_stasis.c:dump_consumer:2202]: Message type received: stasis_subscription_change_type Unsubscribe 490s END /stasis/core/filtering/ - type_filters Time: <1ms Result: PASS 490s START /stasis/core/state/ - explicit_publish 490s END /stasis/core/state/ - explicit_publish Time: 30ms Result: PASS 490s START /stasis/core/state/ - implicit_publish 490s END /stasis/core/state/ - implicit_publish Time: 26ms Result: PASS 490s START /stasis/endpoints/ - channel_messages 490s END /stasis/endpoints/ - channel_messages Time: <1ms Result: PASS 490s START /stasis/endpoints/ - cache_clear 490s END /stasis/endpoints/ - cache_clear Time: <1ms Result: PASS 490s START /stasis/endpoints/ - state_changes 490s END /stasis/endpoints/ - state_changes Time: <1ms Result: PASS 490s START /stasis/res/ - app_invoke_dne 490s END /stasis/res/ - app_invoke_dne Time: <1ms Result: PASS 490s START /stasis/res/ - app_invoke_one 490s END /stasis/res/ - app_invoke_one Time: <1ms Result: PASS 490s START /stasis/res/ - app_replaced 490s END /stasis/res/ - app_replaced Time: <1ms Result: PASS 490s 490s 658 Test(s) Executed 631 Passed 27 Failed 490s Results Generated Successfully: /tmp/autopkgtest.DVfJk3/build.Twg/src/debian/tests/testmods/output/results.txt 490s Some test modules were not loaded: 490s 20a21 490s > test_cel.so 490s 53a55 490s > test_message.so 490s Manually disabled: 490s test_message 490s test_cel 490s 490s 'U' option is not compatible with remote console mode and has no effect. 490s 490s 'U' option is not compatible with remote console mode and has no effect. 490s 490s 'U' option is not compatible with remote console mode and has no effect. 490s 492s autopkgtest [13:20:54]: test asttestmods: -----------------------] 493s autopkgtest [13:20:55]: test asttestmods: - - - - - - - - - - results - - - - - - - - - - 493s asttestmods PASS 494s autopkgtest [13:20:56]: test amr: preparing testbed 655s autopkgtest [13:23:37]: testbed dpkg architecture: ppc64el 655s autopkgtest [13:23:37]: testbed apt version: 2.9.3 655s autopkgtest [13:23:37]: @@@@@@@@@@@@@@@@@@@@ test bed setup 657s Get:1 http://ftpmaster.internal/ubuntu oracular-proposed InRelease [110 kB] 657s Get:2 http://ftpmaster.internal/ubuntu oracular-proposed/main Sources [43.4 kB] 657s Get:3 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse Sources [1680 B] 657s Get:4 http://ftpmaster.internal/ubuntu oracular-proposed/restricted Sources [4792 B] 657s Get:5 http://ftpmaster.internal/ubuntu oracular-proposed/universe Sources [384 kB] 658s Get:6 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el Packages [69.7 kB] 658s Get:7 http://ftpmaster.internal/ubuntu oracular-proposed/universe ppc64el Packages [348 kB] 658s Get:8 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse ppc64el Packages [1392 B] 658s Fetched 964 kB in 1s (664 kB/s) 658s Reading package lists... 664s Reading package lists... 664s Building dependency tree... 664s Reading state information... 664s Calculating upgrade... 664s The following packages will be upgraded: 664s libxml2 665s 1 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 665s Need to get 728 kB of archives. 665s After this operation, 516 kB disk space will be freed. 665s Get:1 http://ftpmaster.internal/ubuntu oracular-proposed/main ppc64el libxml2 ppc64el 2.12.7+dfsg-3 [728 kB] 666s Fetched 728 kB in 1s (755 kB/s) 666s (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 ... 72596 files and directories currently installed.) 666s Preparing to unpack .../libxml2_2.12.7+dfsg-3_ppc64el.deb ... 666s Unpacking libxml2:ppc64el (2.12.7+dfsg-3) over (2.9.14+dfsg-1.3ubuntu3) ... 666s Setting up libxml2:ppc64el (2.12.7+dfsg-3) ... 666s Processing triggers for libc-bin (2.39-0ubuntu8.1) ... 666s Reading package lists... 666s Building dependency tree... 666s Reading state information... 666s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 667s Hit:1 http://ftpmaster.internal/ubuntu oracular-proposed InRelease 667s Hit:2 http://ftpmaster.internal/ubuntu oracular InRelease 667s Hit:3 http://ftpmaster.internal/ubuntu oracular-updates InRelease 667s Hit:4 http://ftpmaster.internal/ubuntu oracular-security InRelease 668s Reading package lists... 668s Reading package lists... 668s Building dependency tree... 668s Reading state information... 669s Calculating upgrade... 669s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 669s Reading package lists... 669s Building dependency tree... 669s Reading state information... 669s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 683s Reading package lists... 683s Building dependency tree... 683s Reading state information... 684s Starting pkgProblemResolver with broken count: 0 684s Starting 2 pkgProblemResolver with broken count: 0 684s Done 684s The following additional packages will be installed: 684s asterisk asterisk-config asterisk-core-sounds-en asterisk-core-sounds-en-gsm 684s asterisk-modules freetds-common libasound2-data libasound2t64 684s libc-client2007e libcodec2-1.2 libevent-2.1-7t64 libgmime-3.0-0t64 libgsm1 684s libical3t64 libiksemel3 libjack-jackd2-0 libltdl7 liblua5.1-0 libneon27t64 684s libodbc2 libogg0 libopencore-amrnb0 libopencore-amrwb0 libopus0 libopusenc0 684s libopusfile0 libportaudio2 libpq5 libradcli4 libresample1 libsamplerate0 684s libsnmp-base libsnmp40t64 libspandsp2t64 libspeex1 libspeexdsp1 libsrtp2-1 684s libsybdb5 libunbound8 liburiparser1 libvo-amrwbenc0 libvorbis0a 684s libvorbisenc2 libvorbisfile3 libxslt1.1 mlock 684s Suggested packages: 684s asterisk-dahdi asterisk-dev asterisk-doc asterisk-ooh323 asterisk-opus 684s alsa-utils libasound2-plugins uw-mailutils jackd2 odbc-postgresql tdsodbc 684s opus-tools snmp-mibs-downloader speex 684s Recommended packages: 684s asterisk-moh-opsound-gsm sox alsa-ucm-conf alsa-topology-conf 684s The following NEW packages will be installed: 684s asterisk asterisk-config asterisk-core-sounds-en asterisk-core-sounds-en-gsm 684s asterisk-modules autopkgtest-satdep freetds-common libasound2-data 684s libasound2t64 libc-client2007e libcodec2-1.2 libevent-2.1-7t64 684s libgmime-3.0-0t64 libgsm1 libical3t64 libiksemel3 libjack-jackd2-0 libltdl7 684s liblua5.1-0 libneon27t64 libodbc2 libogg0 libopencore-amrnb0 684s libopencore-amrwb0 libopus0 libopusenc0 libopusfile0 libportaudio2 libpq5 684s libradcli4 libresample1 libsamplerate0 libsnmp-base libsnmp40t64 684s libspandsp2t64 libspeex1 libspeexdsp1 libsrtp2-1 libsybdb5 libunbound8 684s liburiparser1 libvo-amrwbenc0 libvorbis0a libvorbisenc2 libvorbisfile3 684s libxslt1.1 mlock 684s 0 upgraded, 47 newly installed, 0 to remove and 0 not upgraded. 684s Need to get 26.6 MB/26.6 MB of archives. 684s After this operation, 90.1 MB of additional disk space will be used. 684s Get:1 /tmp/autopkgtest.DVfJk3/2-autopkgtest-satdep.deb autopkgtest-satdep ppc64el 0 [720 B] 684s Get:2 http://ftpmaster.internal/ubuntu oracular/universe ppc64el asterisk-config all 1:20.6.0~dfsg+~cs6.13.40431414-2build5 [242 kB] 684s Get:3 http://ftpmaster.internal/ubuntu oracular/universe ppc64el asterisk-core-sounds-en-gsm all 1.6.1-1 [2417 kB] 686s Get:4 http://ftpmaster.internal/ubuntu oracular/universe ppc64el asterisk-core-sounds-en all 1.6.1-1 [20.6 kB] 686s Get:5 http://ftpmaster.internal/ubuntu oracular/universe ppc64el mlock ppc64el 8:2007f~dfsg-7build3 [8082 B] 686s Get:6 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libc-client2007e ppc64el 8:2007f~dfsg-7build3 [676 kB] 686s Get:7 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libcodec2-1.2 ppc64el 1.2.0-2build1 [9048 kB] 688s Get:8 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libgmime-3.0-0t64 ppc64el 3.2.14+dfsg-2 [206 kB] 688s Get:9 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libgsm1 ppc64el 1.0.22-1build1 [41.9 kB] 688s Get:10 http://ftpmaster.internal/ubuntu oracular/main ppc64el libical3t64 ppc64el 3.0.18-1 [345 kB] 688s Get:11 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libiksemel3 ppc64el 1.4-4build2 [34.8 kB] 688s Get:12 http://ftpmaster.internal/ubuntu oracular/main ppc64el libopus0 ppc64el 1.4-1build1 [322 kB] 688s Get:13 http://ftpmaster.internal/ubuntu oracular/main ppc64el libsamplerate0 ppc64el 0.2.2-4build1 [1348 kB] 688s Get:14 http://ftpmaster.internal/ubuntu oracular/main ppc64el libjack-jackd2-0 ppc64el 1.9.21~dfsg-3ubuntu3 [340 kB] 688s Get:15 http://ftpmaster.internal/ubuntu oracular/universe ppc64el liblua5.1-0 ppc64el 5.1.5-9build2 [157 kB] 688s Get:16 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libneon27t64 ppc64el 0.33.0-1.1build3 [120 kB] 688s Get:17 http://ftpmaster.internal/ubuntu oracular/main ppc64el libltdl7 ppc64el 2.4.7-7build1 [48.2 kB] 688s Get:18 http://ftpmaster.internal/ubuntu oracular/main ppc64el libodbc2 ppc64el 2.3.12-1build2 [188 kB] 688s Get:19 http://ftpmaster.internal/ubuntu oracular/main ppc64el libogg0 ppc64el 1.3.5-3build1 [27.6 kB] 688s Get:20 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libopencore-amrnb0 ppc64el 0.1.6-1build1 [165 kB] 688s Get:21 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libopencore-amrwb0 ppc64el 0.1.6-1build1 [91.2 kB] 688s Get:22 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libopusenc0 ppc64el 0.2.1-2build1 [34.5 kB] 688s Get:23 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libopusfile0 ppc64el 0.12-4build3 [60.6 kB] 688s Get:24 http://ftpmaster.internal/ubuntu oracular/main ppc64el libasound2-data all 1.2.11-1build2 [21.0 kB] 688s Get:25 http://ftpmaster.internal/ubuntu oracular/main ppc64el libasound2t64 ppc64el 1.2.11-1build2 [502 kB] 688s Get:26 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libportaudio2 ppc64el 19.6.0-1.2build3 [87.5 kB] 688s Get:27 http://ftpmaster.internal/ubuntu oracular/main ppc64el libpq5 ppc64el 16.3-1 [171 kB] 688s Get:28 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libradcli4 ppc64el 1.2.11-1build3 [45.5 kB] 688s Get:29 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libresample1 ppc64el 0.1.3-6 [11.1 kB] 688s Get:30 http://ftpmaster.internal/ubuntu oracular/main ppc64el libsnmp-base all 5.9.4+dfsg-1.1ubuntu3 [206 kB] 688s Get:31 http://ftpmaster.internal/ubuntu oracular/main ppc64el libsnmp40t64 ppc64el 5.9.4+dfsg-1.1ubuntu3 [1206 kB] 688s Get:32 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libspandsp2t64 ppc64el 0.0.6+dfsg-2.1build1 [399 kB] 688s Get:33 http://ftpmaster.internal/ubuntu oracular/main ppc64el libspeex1 ppc64el 1.2.1-2ubuntu2 [111 kB] 688s Get:34 http://ftpmaster.internal/ubuntu oracular/main ppc64el libspeexdsp1 ppc64el 1.2.1-1ubuntu3 [75.0 kB] 688s Get:35 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libsrtp2-1 ppc64el 2.5.0-3build1 [51.4 kB] 688s Get:36 http://ftpmaster.internal/ubuntu oracular/main ppc64el freetds-common all 1.3.17+ds-2build3 [26.9 kB] 688s Get:37 http://ftpmaster.internal/ubuntu oracular/main ppc64el libsybdb5 ppc64el 1.3.17+ds-2build3 [238 kB] 688s Get:38 http://ftpmaster.internal/ubuntu oracular/main ppc64el libevent-2.1-7t64 ppc64el 2.1.12-stable-10 [172 kB] 688s Get:39 http://ftpmaster.internal/ubuntu oracular/main ppc64el libunbound8 ppc64el 1.19.2-1ubuntu3 [537 kB] 688s Get:40 http://ftpmaster.internal/ubuntu oracular/universe ppc64el libvo-amrwbenc0 ppc64el 0.1.3-2build1 [126 kB] 688s Get:41 http://ftpmaster.internal/ubuntu oracular/main ppc64el libvorbis0a ppc64el 1.3.7-2 [142 kB] 688s Get:42 http://ftpmaster.internal/ubuntu oracular/main ppc64el libvorbisenc2 ppc64el 1.3.7-2 [86.2 kB] 688s Get:43 http://ftpmaster.internal/ubuntu oracular/main ppc64el libvorbisfile3 ppc64el 1.3.7-2 [22.5 kB] 688s Get:44 http://ftpmaster.internal/ubuntu oracular/universe ppc64el asterisk-modules ppc64el 1:20.6.0~dfsg+~cs6.13.40431414-2build5 [3407 kB] 689s Get:45 http://ftpmaster.internal/ubuntu oracular/universe ppc64el liburiparser1 ppc64el 0.9.7+dfsg-2build1 [53.6 kB] 689s Get:46 http://ftpmaster.internal/ubuntu oracular/main ppc64el libxslt1.1 ppc64el 1.1.39-0exp1build1 [192 kB] 689s Get:47 http://ftpmaster.internal/ubuntu oracular/universe ppc64el asterisk ppc64el 1:20.6.0~dfsg+~cs6.13.40431414-2build5 [2812 kB] 689s Fetched 26.6 MB in 5s (5441 kB/s) 689s Selecting previously unselected package asterisk-config. 689s (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 ... 72596 files and directories currently installed.) 689s Preparing to unpack .../00-asterisk-config_1%3a20.6.0~dfsg+~cs6.13.40431414-2build5_all.deb ... 689s Unpacking asterisk-config (1:20.6.0~dfsg+~cs6.13.40431414-2build5) ... 689s Selecting previously unselected package asterisk-core-sounds-en-gsm. 689s Preparing to unpack .../01-asterisk-core-sounds-en-gsm_1.6.1-1_all.deb ... 689s Unpacking asterisk-core-sounds-en-gsm (1.6.1-1) ... 689s Selecting previously unselected package asterisk-core-sounds-en. 689s Preparing to unpack .../02-asterisk-core-sounds-en_1.6.1-1_all.deb ... 689s Unpacking asterisk-core-sounds-en (1.6.1-1) ... 689s Selecting previously unselected package mlock. 689s Preparing to unpack .../03-mlock_8%3a2007f~dfsg-7build3_ppc64el.deb ... 689s Unpacking mlock (8:2007f~dfsg-7build3) ... 689s Selecting previously unselected package libc-client2007e. 689s Preparing to unpack .../04-libc-client2007e_8%3a2007f~dfsg-7build3_ppc64el.deb ... 689s Unpacking libc-client2007e (8:2007f~dfsg-7build3) ... 689s Selecting previously unselected package libcodec2-1.2:ppc64el. 689s Preparing to unpack .../05-libcodec2-1.2_1.2.0-2build1_ppc64el.deb ... 689s Unpacking libcodec2-1.2:ppc64el (1.2.0-2build1) ... 689s Selecting previously unselected package libgmime-3.0-0t64:ppc64el. 689s Preparing to unpack .../06-libgmime-3.0-0t64_3.2.14+dfsg-2_ppc64el.deb ... 689s Unpacking libgmime-3.0-0t64:ppc64el (3.2.14+dfsg-2) ... 689s Selecting previously unselected package libgsm1:ppc64el. 689s Preparing to unpack .../07-libgsm1_1.0.22-1build1_ppc64el.deb ... 689s Unpacking libgsm1:ppc64el (1.0.22-1build1) ... 689s Selecting previously unselected package libical3t64:ppc64el. 689s Preparing to unpack .../08-libical3t64_3.0.18-1_ppc64el.deb ... 689s Unpacking libical3t64:ppc64el (3.0.18-1) ... 690s Selecting previously unselected package libiksemel3:ppc64el. 690s Preparing to unpack .../09-libiksemel3_1.4-4build2_ppc64el.deb ... 690s Unpacking libiksemel3:ppc64el (1.4-4build2) ... 690s Selecting previously unselected package libopus0:ppc64el. 690s Preparing to unpack .../10-libopus0_1.4-1build1_ppc64el.deb ... 690s Unpacking libopus0:ppc64el (1.4-1build1) ... 690s Selecting previously unselected package libsamplerate0:ppc64el. 690s Preparing to unpack .../11-libsamplerate0_0.2.2-4build1_ppc64el.deb ... 690s Unpacking libsamplerate0:ppc64el (0.2.2-4build1) ... 690s Selecting previously unselected package libjack-jackd2-0:ppc64el. 690s Preparing to unpack .../12-libjack-jackd2-0_1.9.21~dfsg-3ubuntu3_ppc64el.deb ... 690s Unpacking libjack-jackd2-0:ppc64el (1.9.21~dfsg-3ubuntu3) ... 690s Selecting previously unselected package liblua5.1-0:ppc64el. 690s Preparing to unpack .../13-liblua5.1-0_5.1.5-9build2_ppc64el.deb ... 690s Unpacking liblua5.1-0:ppc64el (5.1.5-9build2) ... 690s Selecting previously unselected package libneon27t64:ppc64el. 690s Preparing to unpack .../14-libneon27t64_0.33.0-1.1build3_ppc64el.deb ... 690s Unpacking libneon27t64:ppc64el (0.33.0-1.1build3) ... 690s Selecting previously unselected package libltdl7:ppc64el. 690s Preparing to unpack .../15-libltdl7_2.4.7-7build1_ppc64el.deb ... 690s Unpacking libltdl7:ppc64el (2.4.7-7build1) ... 690s Selecting previously unselected package libodbc2:ppc64el. 690s Preparing to unpack .../16-libodbc2_2.3.12-1build2_ppc64el.deb ... 690s Unpacking libodbc2:ppc64el (2.3.12-1build2) ... 690s Selecting previously unselected package libogg0:ppc64el. 690s Preparing to unpack .../17-libogg0_1.3.5-3build1_ppc64el.deb ... 690s Unpacking libogg0:ppc64el (1.3.5-3build1) ... 690s Selecting previously unselected package libopencore-amrnb0:ppc64el. 690s Preparing to unpack .../18-libopencore-amrnb0_0.1.6-1build1_ppc64el.deb ... 690s Unpacking libopencore-amrnb0:ppc64el (0.1.6-1build1) ... 690s Selecting previously unselected package libopencore-amrwb0:ppc64el. 690s Preparing to unpack .../19-libopencore-amrwb0_0.1.6-1build1_ppc64el.deb ... 690s Unpacking libopencore-amrwb0:ppc64el (0.1.6-1build1) ... 690s Selecting previously unselected package libopusenc0:ppc64el. 690s Preparing to unpack .../20-libopusenc0_0.2.1-2build1_ppc64el.deb ... 690s Unpacking libopusenc0:ppc64el (0.2.1-2build1) ... 690s Selecting previously unselected package libopusfile0:ppc64el. 690s Preparing to unpack .../21-libopusfile0_0.12-4build3_ppc64el.deb ... 690s Unpacking libopusfile0:ppc64el (0.12-4build3) ... 690s Selecting previously unselected package libasound2-data. 690s Preparing to unpack .../22-libasound2-data_1.2.11-1build2_all.deb ... 690s Unpacking libasound2-data (1.2.11-1build2) ... 690s Selecting previously unselected package libasound2t64:ppc64el. 690s Preparing to unpack .../23-libasound2t64_1.2.11-1build2_ppc64el.deb ... 690s Unpacking libasound2t64:ppc64el (1.2.11-1build2) ... 690s Selecting previously unselected package libportaudio2:ppc64el. 690s Preparing to unpack .../24-libportaudio2_19.6.0-1.2build3_ppc64el.deb ... 690s Unpacking libportaudio2:ppc64el (19.6.0-1.2build3) ... 690s Selecting previously unselected package libpq5:ppc64el. 690s Preparing to unpack .../25-libpq5_16.3-1_ppc64el.deb ... 690s Unpacking libpq5:ppc64el (16.3-1) ... 690s Selecting previously unselected package libradcli4. 690s Preparing to unpack .../26-libradcli4_1.2.11-1build3_ppc64el.deb ... 690s Unpacking libradcli4 (1.2.11-1build3) ... 690s Selecting previously unselected package libresample1. 690s Preparing to unpack .../27-libresample1_0.1.3-6_ppc64el.deb ... 690s Unpacking libresample1 (0.1.3-6) ... 690s Selecting previously unselected package libsnmp-base. 690s Preparing to unpack .../28-libsnmp-base_5.9.4+dfsg-1.1ubuntu3_all.deb ... 690s Unpacking libsnmp-base (5.9.4+dfsg-1.1ubuntu3) ... 690s Selecting previously unselected package libsnmp40t64:ppc64el. 690s Preparing to unpack .../29-libsnmp40t64_5.9.4+dfsg-1.1ubuntu3_ppc64el.deb ... 690s Unpacking libsnmp40t64:ppc64el (5.9.4+dfsg-1.1ubuntu3) ... 690s Selecting previously unselected package libspandsp2t64:ppc64el. 690s Preparing to unpack .../30-libspandsp2t64_0.0.6+dfsg-2.1build1_ppc64el.deb ... 690s Unpacking libspandsp2t64:ppc64el (0.0.6+dfsg-2.1build1) ... 690s Selecting previously unselected package libspeex1:ppc64el. 690s Preparing to unpack .../31-libspeex1_1.2.1-2ubuntu2_ppc64el.deb ... 690s Unpacking libspeex1:ppc64el (1.2.1-2ubuntu2) ... 690s Selecting previously unselected package libspeexdsp1:ppc64el. 690s Preparing to unpack .../32-libspeexdsp1_1.2.1-1ubuntu3_ppc64el.deb ... 690s Unpacking libspeexdsp1:ppc64el (1.2.1-1ubuntu3) ... 690s Selecting previously unselected package libsrtp2-1:ppc64el. 690s Preparing to unpack .../33-libsrtp2-1_2.5.0-3build1_ppc64el.deb ... 690s Unpacking libsrtp2-1:ppc64el (2.5.0-3build1) ... 690s Selecting previously unselected package freetds-common. 690s Preparing to unpack .../34-freetds-common_1.3.17+ds-2build3_all.deb ... 690s Unpacking freetds-common (1.3.17+ds-2build3) ... 690s Selecting previously unselected package libsybdb5:ppc64el. 690s Preparing to unpack .../35-libsybdb5_1.3.17+ds-2build3_ppc64el.deb ... 690s Unpacking libsybdb5:ppc64el (1.3.17+ds-2build3) ... 690s Selecting previously unselected package libevent-2.1-7t64:ppc64el. 690s Preparing to unpack .../36-libevent-2.1-7t64_2.1.12-stable-10_ppc64el.deb ... 690s Unpacking libevent-2.1-7t64:ppc64el (2.1.12-stable-10) ... 690s Selecting previously unselected package libunbound8:ppc64el. 690s Preparing to unpack .../37-libunbound8_1.19.2-1ubuntu3_ppc64el.deb ... 690s Unpacking libunbound8:ppc64el (1.19.2-1ubuntu3) ... 690s Selecting previously unselected package libvo-amrwbenc0:ppc64el. 690s Preparing to unpack .../38-libvo-amrwbenc0_0.1.3-2build1_ppc64el.deb ... 690s Unpacking libvo-amrwbenc0:ppc64el (0.1.3-2build1) ... 690s Selecting previously unselected package libvorbis0a:ppc64el. 690s Preparing to unpack .../39-libvorbis0a_1.3.7-2_ppc64el.deb ... 690s Unpacking libvorbis0a:ppc64el (1.3.7-2) ... 690s Selecting previously unselected package libvorbisenc2:ppc64el. 690s Preparing to unpack .../40-libvorbisenc2_1.3.7-2_ppc64el.deb ... 690s Unpacking libvorbisenc2:ppc64el (1.3.7-2) ... 690s Selecting previously unselected package libvorbisfile3:ppc64el. 690s Preparing to unpack .../41-libvorbisfile3_1.3.7-2_ppc64el.deb ... 690s Unpacking libvorbisfile3:ppc64el (1.3.7-2) ... 690s Selecting previously unselected package asterisk-modules. 690s Preparing to unpack .../42-asterisk-modules_1%3a20.6.0~dfsg+~cs6.13.40431414-2build5_ppc64el.deb ... 690s Unpacking asterisk-modules (1:20.6.0~dfsg+~cs6.13.40431414-2build5) ... 690s Selecting previously unselected package liburiparser1:ppc64el. 690s Preparing to unpack .../43-liburiparser1_0.9.7+dfsg-2build1_ppc64el.deb ... 690s Unpacking liburiparser1:ppc64el (0.9.7+dfsg-2build1) ... 690s Selecting previously unselected package libxslt1.1:ppc64el. 690s Preparing to unpack .../44-libxslt1.1_1.1.39-0exp1build1_ppc64el.deb ... 690s Unpacking libxslt1.1:ppc64el (1.1.39-0exp1build1) ... 690s Selecting previously unselected package asterisk. 690s Preparing to unpack .../45-asterisk_1%3a20.6.0~dfsg+~cs6.13.40431414-2build5_ppc64el.deb ... 690s Unpacking asterisk (1:20.6.0~dfsg+~cs6.13.40431414-2build5) ... 691s Selecting previously unselected package autopkgtest-satdep. 691s Preparing to unpack .../46-2-autopkgtest-satdep.deb ... 691s Unpacking autopkgtest-satdep (0) ... 691s Setting up libvo-amrwbenc0:ppc64el (0.1.3-2build1) ... 691s Setting up libneon27t64:ppc64el (0.33.0-1.1build3) ... 691s Setting up libogg0:ppc64el (1.3.5-3build1) ... 691s Setting up libspeex1:ppc64el (1.2.1-2ubuntu2) ... 691s Setting up libgsm1:ppc64el (1.0.22-1build1) ... 691s Setting up asterisk-core-sounds-en-gsm (1.6.1-1) ... 691s Setting up libsnmp-base (5.9.4+dfsg-1.1ubuntu3) ... 691s Setting up libcodec2-1.2:ppc64el (1.2.0-2build1) ... 691s Setting up mlock (8:2007f~dfsg-7build3) ... 691s Setting up libsrtp2-1:ppc64el (2.5.0-3build1) ... 691s Setting up libpq5:ppc64el (16.3-1) ... 691s Setting up libevent-2.1-7t64:ppc64el (2.1.12-stable-10) ... 691s Setting up libasound2-data (1.2.11-1build2) ... 691s Setting up libopencore-amrwb0:ppc64el (0.1.6-1build1) ... 691s Setting up libunbound8:ppc64el (1.19.2-1ubuntu3) ... 691s Setting up libasound2t64:ppc64el (1.2.11-1build2) ... 691s Setting up libradcli4 (1.2.11-1build3) ... 691s Setting up libopus0:ppc64el (1.4-1build1) ... 691s Setting up asterisk-config (1:20.6.0~dfsg+~cs6.13.40431414-2build5) ... 691s Setting up libvorbis0a:ppc64el (1.3.7-2) ... 691s Setting up libical3t64:ppc64el (3.0.18-1) ... 691s Setting up libltdl7:ppc64el (2.4.7-7build1) ... 691s Setting up asterisk-core-sounds-en (1.6.1-1) ... 691s update-alternatives: using /usr/share/asterisk/sounds/en_US_f_Allison to provide /usr/share/asterisk/sounds/en (asterisk-prompt-en) in auto mode 691s 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 691s Setting up libiksemel3:ppc64el (1.4-4build2) ... 691s Setting up libodbc2:ppc64el (2.3.12-1build2) ... 691s Setting up liburiparser1:ppc64el (0.9.7+dfsg-2build1) ... 691s Setting up libspandsp2t64:ppc64el (0.0.6+dfsg-2.1build1) ... 691s Setting up libspeexdsp1:ppc64el (1.2.1-1ubuntu3) ... 691s Setting up liblua5.1-0:ppc64el (5.1.5-9build2) ... 691s Setting up libxslt1.1:ppc64el (1.1.39-0exp1build1) ... 691s Setting up libopencore-amrnb0:ppc64el (0.1.6-1build1) ... 691s Setting up libc-client2007e (8:2007f~dfsg-7build3) ... 691s Setting up libresample1 (0.1.3-6) ... 691s Setting up freetds-common (1.3.17+ds-2build3) ... 691s Setting up libgmime-3.0-0t64:ppc64el (3.2.14+dfsg-2) ... 691s Setting up libsamplerate0:ppc64el (0.2.2-4build1) ... 691s Setting up libopusfile0:ppc64el (0.12-4build3) ... 691s Setting up libvorbisenc2:ppc64el (1.3.7-2) ... 691s Setting up libopusenc0:ppc64el (0.2.1-2build1) ... 691s Setting up libsnmp40t64:ppc64el (5.9.4+dfsg-1.1ubuntu3) ... 691s Setting up libsybdb5:ppc64el (1.3.17+ds-2build3) ... 691s Setting up libvorbisfile3:ppc64el (1.3.7-2) ... 691s Setting up libjack-jackd2-0:ppc64el (1.9.21~dfsg-3ubuntu3) ... 691s Setting up libportaudio2:ppc64el (19.6.0-1.2build3) ... 691s Setting up asterisk-modules (1:20.6.0~dfsg+~cs6.13.40431414-2build5) ... 691s Setting up asterisk (1:20.6.0~dfsg+~cs6.13.40431414-2build5) ... 691s Adding system user for Asterisk 691s info: Adding user `asterisk' to group `dialout' ... 691s info: Adding user `asterisk' to group `audio' ... 692s Created symlink /etc/systemd/system/multi-user.target.wants/asterisk.service → /usr/lib/systemd/system/asterisk.service. 693s Setting up autopkgtest-satdep (0) ... 693s Processing triggers for man-db (2.12.1-1) ... 694s Processing triggers for libc-bin (2.39-0ubuntu8.1) ... 700s (Reading database ... 74515 files and directories currently installed.) 700s Removing autopkgtest-satdep (0) ... 727s autopkgtest [13:24:49]: test amr: [----------------------- 727s 1 audio amr amr (AMR) 727s 2 audio amrwb amrwb (AMR-WB) 727s amr amrwb codec2 ulaw alaw gsm g726 g726aal2 adpcm slin8 slin12 slin16 slin24 slin32 slin44 slin48 slin96 slin192 lpc10 speex8 speex16 speex32 g722 opus 727s amr - 23000 15000 15000 15000 15000 15000 15000 15000 9000 17000 17000 17000 17000 17000 17000 17000 17000 15000 15000 23000 23000 17250 15000 727s amr amrwb codec2 ulaw alaw gsm g726 g726aal2 adpcm slin8 slin12 slin16 slin24 slin32 slin44 slin48 slin96 slin192 lpc10 speex8 speex16 speex32 g722 opus 727s amrwb 23500 - 23500 23500 23500 23500 23500 23500 23500 17500 17500 9000 17000 17000 17000 17000 17000 17000 23500 23500 15000 23000 15000 14999 728s autopkgtest [13:24:50]: test amr: -----------------------] 728s amr PASS 728s autopkgtest [13:24:50]: test amr: - - - - - - - - - - results - - - - - - - - - - 729s autopkgtest [13:24:51]: @@@@@@@@@@@@@@@@@@@@ summary 729s asttestmods PASS 729s amr PASS 749s Creating nova instance adt-oracular-ppc64el-asterisk-20240603-131242-juju-7f2275-prod-proposed-migration-environment-3-c62801ba-782e-4817-a0a3-36cb1b2cc2bb from image adt/ubuntu-oracular-ppc64el-server-20240603.img (UUID 062f8fe3-b9b8-44c5-9911-f4a93486fbaf)... 749s Creating nova instance adt-oracular-ppc64el-asterisk-20240603-131242-juju-7f2275-prod-proposed-migration-environment-3-c62801ba-782e-4817-a0a3-36cb1b2cc2bb from image adt/ubuntu-oracular-ppc64el-server-20240603.img (UUID 062f8fe3-b9b8-44c5-9911-f4a93486fbaf)...