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