0s autopkgtest [21:29:08]: starting date and time: 2024-04-08 21:29:08+0000 0s autopkgtest [21:29:08]: git checkout: 43bc6cdf gitlab-ci: do not include the salsa pipeline 0s autopkgtest [21:29:08]: host juju-7f2275-prod-proposed-migration-environment-2; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.max6bl1e/out --timeout-copy=6000 --setup-commands /home/ubuntu/autopkgtest-cloud/worker-config-production/setup-canonical.sh --apt-pocket=proposed=src:curl --apt-upgrade asterisk --timeout-short=300 --timeout-copy=20000 --timeout-build=20000 --env=ADT_TEST_TRIGGERS=curl/8.5.0-2ubuntu10 -- ssh -s /home/ubuntu/autopkgtest/ssh-setup/nova -- --flavor autopkgtest --security-groups autopkgtest-juju-7f2275-prod-proposed-migration-environment-2@lcy02-2.secgroup --name adt-noble-amd64-asterisk-20240408-212908-juju-7f2275-prod-proposed-migration-environment-2-123057e4-f667-4a03-bcf1-9dc6ceedd8ec --image adt/ubuntu-noble-amd64-server --keyname testbed-juju-7f2275-prod-proposed-migration-environment-2 --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,launchpadlibrarian.net,launchpadcontent.net,launchpad.net,10.24.0.0/24,keystone.ps5.canonical.com,objectstorage.prodstack5.canonical.com'"'"'' --mirror=http://ftpmaster.internal/ubuntu/ 1135s autopkgtest [21:48:03]: testbed dpkg architecture: amd64 1135s autopkgtest [21:48:03]: testbed apt version: 2.7.14build2 1135s autopkgtest [21:48:03]: @@@@@@@@@@@@@@@@@@@@ test bed setup 1136s Get:1 http://ftpmaster.internal/ubuntu noble-proposed InRelease [117 kB] 1136s Get:2 http://ftpmaster.internal/ubuntu noble-proposed/multiverse Sources [10.6 kB] 1136s Get:3 http://ftpmaster.internal/ubuntu noble-proposed/restricted Sources [4680 B] 1136s Get:4 http://ftpmaster.internal/ubuntu noble-proposed/universe Sources [831 kB] 1136s Get:5 http://ftpmaster.internal/ubuntu noble-proposed/main Sources [358 kB] 1136s Get:6 http://ftpmaster.internal/ubuntu noble-proposed/main i386 Packages [269 kB] 1136s Get:7 http://ftpmaster.internal/ubuntu noble-proposed/main amd64 Packages [357 kB] 1136s Get:8 http://ftpmaster.internal/ubuntu noble-proposed/main amd64 c-n-f Metadata [3508 B] 1136s Get:9 http://ftpmaster.internal/ubuntu noble-proposed/restricted i386 Packages [5016 B] 1136s Get:10 http://ftpmaster.internal/ubuntu noble-proposed/restricted amd64 Packages [16.3 kB] 1136s Get:11 http://ftpmaster.internal/ubuntu noble-proposed/restricted amd64 c-n-f Metadata [116 B] 1136s Get:12 http://ftpmaster.internal/ubuntu noble-proposed/universe amd64 Packages [1044 kB] 1136s Get:13 http://ftpmaster.internal/ubuntu noble-proposed/universe i386 Packages [449 kB] 1136s Get:14 http://ftpmaster.internal/ubuntu noble-proposed/universe amd64 c-n-f Metadata [9396 B] 1136s Get:15 http://ftpmaster.internal/ubuntu noble-proposed/multiverse i386 Packages [2044 B] 1136s Get:16 http://ftpmaster.internal/ubuntu noble-proposed/multiverse amd64 Packages [9440 B] 1136s Get:17 http://ftpmaster.internal/ubuntu noble-proposed/multiverse amd64 c-n-f Metadata [196 B] 1138s Fetched 3486 kB in 1s (5876 kB/s) 1138s Reading package lists... 1140s Reading package lists... 1140s Building dependency tree... 1140s Reading state information... 1141s Calculating upgrade... 1141s The following packages will be upgraded: 1141s bash curl grub-common grub-pc grub-pc-bin grub2-common libcurl3t64-gnutls 1141s libcurl4t64 libpython3.12-minimal libpython3.12-stdlib libsasl2-2 1141s libsasl2-modules libsasl2-modules-db python3-gi python3.12 1141s python3.12-minimal shim-signed 1141s 17 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 1141s Need to get 12.6 MB of archives. 1141s After this operation, 34.8 kB disk space will be freed. 1141s Get:1 http://ftpmaster.internal/ubuntu noble/main amd64 bash amd64 5.2.21-2ubuntu4 [794 kB] 1141s Get:2 http://ftpmaster.internal/ubuntu noble/main amd64 python3.12 amd64 3.12.2-5ubuntu3 [644 kB] 1141s Get:3 http://ftpmaster.internal/ubuntu noble/main amd64 libpython3.12-stdlib amd64 3.12.2-5ubuntu3 [2067 kB] 1141s Get:4 http://ftpmaster.internal/ubuntu noble/main amd64 python3.12-minimal amd64 3.12.2-5ubuntu3 [2337 kB] 1141s Get:5 http://ftpmaster.internal/ubuntu noble/main amd64 libpython3.12-minimal amd64 3.12.2-5ubuntu3 [833 kB] 1141s Get:6 http://ftpmaster.internal/ubuntu noble/main amd64 python3-gi amd64 3.48.2-1 [232 kB] 1141s Get:7 http://ftpmaster.internal/ubuntu noble-proposed/main amd64 curl amd64 8.5.0-2ubuntu10 [227 kB] 1141s Get:8 http://ftpmaster.internal/ubuntu noble-proposed/main amd64 libcurl4t64 amd64 8.5.0-2ubuntu10 [340 kB] 1141s Get:9 http://ftpmaster.internal/ubuntu noble/main amd64 grub-pc amd64 2.12-1ubuntu7 [137 kB] 1141s Get:10 http://ftpmaster.internal/ubuntu noble/main amd64 grub2-common amd64 2.12-1ubuntu7 [669 kB] 1141s Get:11 http://ftpmaster.internal/ubuntu noble/main amd64 grub-pc-bin amd64 2.12-1ubuntu7 [1097 kB] 1141s Get:12 http://ftpmaster.internal/ubuntu noble/main amd64 grub-common amd64 2.12-1ubuntu7 [2120 kB] 1141s Get:13 http://ftpmaster.internal/ubuntu noble-proposed/main amd64 libcurl3t64-gnutls amd64 8.5.0-2ubuntu10 [333 kB] 1141s Get:14 http://ftpmaster.internal/ubuntu noble/main amd64 libsasl2-modules-db amd64 2.1.28+dfsg1-5ubuntu3 [20.3 kB] 1141s Get:15 http://ftpmaster.internal/ubuntu noble/main amd64 libsasl2-2 amd64 2.1.28+dfsg1-5ubuntu3 [53.2 kB] 1141s Get:16 http://ftpmaster.internal/ubuntu noble/main amd64 libsasl2-modules amd64 2.1.28+dfsg1-5ubuntu3 [69.7 kB] 1141s Get:17 http://ftpmaster.internal/ubuntu noble/main amd64 shim-signed amd64 1.58+15.8-0ubuntu1 [665 kB] 1142s Preconfiguring packages ... 1142s Fetched 12.6 MB in 0s (102 MB/s) 1142s (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 ... 105900 files and directories currently installed.) 1142s Preparing to unpack .../bash_5.2.21-2ubuntu4_amd64.deb ... 1142s Unpacking bash (5.2.21-2ubuntu4) over (5.2.21-2ubuntu2) ... 1142s Setting up bash (5.2.21-2ubuntu4) ... 1142s update-alternatives: using /usr/share/man/man7/bash-builtins.7.gz to provide /usr/share/man/man7/builtins.7.gz (builtins.7.gz) in auto mode 1142s (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 ... 105900 files and directories currently installed.) 1142s Preparing to unpack .../00-python3.12_3.12.2-5ubuntu3_amd64.deb ... 1142s Unpacking python3.12 (3.12.2-5ubuntu3) over (3.12.2-4build4) ... 1142s Preparing to unpack .../01-libpython3.12-stdlib_3.12.2-5ubuntu3_amd64.deb ... 1143s Unpacking libpython3.12-stdlib:amd64 (3.12.2-5ubuntu3) over (3.12.2-4build4) ... 1143s Preparing to unpack .../02-python3.12-minimal_3.12.2-5ubuntu3_amd64.deb ... 1143s Unpacking python3.12-minimal (3.12.2-5ubuntu3) over (3.12.2-4build4) ... 1143s Preparing to unpack .../03-libpython3.12-minimal_3.12.2-5ubuntu3_amd64.deb ... 1143s Unpacking libpython3.12-minimal:amd64 (3.12.2-5ubuntu3) over (3.12.2-4build4) ... 1143s Preparing to unpack .../04-python3-gi_3.48.2-1_amd64.deb ... 1143s Unpacking python3-gi (3.48.2-1) over (3.48.1-1build1) ... 1143s Preparing to unpack .../05-curl_8.5.0-2ubuntu10_amd64.deb ... 1143s Unpacking curl (8.5.0-2ubuntu10) over (8.5.0-2ubuntu9) ... 1143s Preparing to unpack .../06-libcurl4t64_8.5.0-2ubuntu10_amd64.deb ... 1143s Unpacking libcurl4t64:amd64 (8.5.0-2ubuntu10) over (8.5.0-2ubuntu9) ... 1143s Preparing to unpack .../07-grub-pc_2.12-1ubuntu7_amd64.deb ... 1143s Unpacking grub-pc (2.12-1ubuntu7) over (2.12-1ubuntu6) ... 1143s Preparing to unpack .../08-grub2-common_2.12-1ubuntu7_amd64.deb ... 1143s Unpacking grub2-common (2.12-1ubuntu7) over (2.12-1ubuntu6) ... 1143s Preparing to unpack .../09-grub-pc-bin_2.12-1ubuntu7_amd64.deb ... 1143s Unpacking grub-pc-bin (2.12-1ubuntu7) over (2.12-1ubuntu6) ... 1144s Preparing to unpack .../10-grub-common_2.12-1ubuntu7_amd64.deb ... 1144s Unpacking grub-common (2.12-1ubuntu7) over (2.12-1ubuntu6) ... 1144s Preparing to unpack .../11-libcurl3t64-gnutls_8.5.0-2ubuntu10_amd64.deb ... 1144s Unpacking libcurl3t64-gnutls:amd64 (8.5.0-2ubuntu10) over (8.5.0-2ubuntu9) ... 1144s Preparing to unpack .../12-libsasl2-modules-db_2.1.28+dfsg1-5ubuntu3_amd64.deb ... 1144s Unpacking libsasl2-modules-db:amd64 (2.1.28+dfsg1-5ubuntu3) over (2.1.28+dfsg1-5ubuntu2) ... 1144s Preparing to unpack .../13-libsasl2-2_2.1.28+dfsg1-5ubuntu3_amd64.deb ... 1144s Unpacking libsasl2-2:amd64 (2.1.28+dfsg1-5ubuntu3) over (2.1.28+dfsg1-5ubuntu2) ... 1144s Preparing to unpack .../14-libsasl2-modules_2.1.28+dfsg1-5ubuntu3_amd64.deb ... 1144s Unpacking libsasl2-modules:amd64 (2.1.28+dfsg1-5ubuntu3) over (2.1.28+dfsg1-5ubuntu2) ... 1144s Preparing to unpack .../15-shim-signed_1.58+15.8-0ubuntu1_amd64.deb ... 1144s Unpacking shim-signed (1.58+15.8-0ubuntu1) over (1.57+15.8-0ubuntu1) ... 1144s Setting up libcurl4t64:amd64 (8.5.0-2ubuntu10) ... 1144s Setting up libsasl2-modules:amd64 (2.1.28+dfsg1-5ubuntu3) ... 1144s Setting up libpython3.12-minimal:amd64 (3.12.2-5ubuntu3) ... 1144s Setting up libcurl3t64-gnutls:amd64 (8.5.0-2ubuntu10) ... 1144s Setting up libsasl2-modules-db:amd64 (2.1.28+dfsg1-5ubuntu3) ... 1144s Setting up grub-common (2.12-1ubuntu7) ... 1144s update-rc.d: warning: start and stop actions are no longer supported; falling back to defaults 1145s Setting up python3-gi (3.48.2-1) ... 1145s Setting up libsasl2-2:amd64 (2.1.28+dfsg1-5ubuntu3) ... 1145s Setting up curl (8.5.0-2ubuntu10) ... 1145s Setting up python3.12-minimal (3.12.2-5ubuntu3) ... 1146s Setting up libpython3.12-stdlib:amd64 (3.12.2-5ubuntu3) ... 1146s Setting up grub2-common (2.12-1ubuntu7) ... 1146s Setting up python3.12 (3.12.2-5ubuntu3) ... 1147s Setting up grub-pc-bin (2.12-1ubuntu7) ... 1147s Setting up shim-signed (1.58+15.8-0ubuntu1) ... 1147s Installing for x86_64-efi platform. 1148s grub-install: warning: EFI variables cannot be set on this system. 1148s grub-install: warning: You will have to complete the GRUB setup manually. 1148s Installation finished. No error reported. 1148s Setting up grub-pc (2.12-1ubuntu7) ... 1148s Installing for i386-pc platform. 1148s Installation finished. No error reported. 1149s Sourcing file `/etc/default/grub' 1149s Sourcing file `/etc/default/grub.d/50-cloudimg-settings.cfg' 1149s Sourcing file `/etc/default/grub.d/90-autopkgtest.cfg' 1149s Generating grub configuration file ... 1149s Found linux image: /boot/vmlinuz-6.8.0-22-generic 1149s Found initrd image: /boot/initrd.img-6.8.0-22-generic 1149s Found linux image: /boot/vmlinuz-6.8.0-11-generic 1149s Found initrd image: /boot/initrd.img-6.8.0-11-generic 1149s Warning: os-prober will not be executed to detect other bootable partitions. 1149s Systems on them will not be added to the GRUB boot configuration. 1149s Check GRUB_DISABLE_OS_PROBER documentation entry. 1149s Adding boot menu entry for UEFI Firmware Settings ... 1149s done 1149s Processing triggers for install-info (7.1-3build2) ... 1149s Processing triggers for libc-bin (2.39-0ubuntu8) ... 1149s Processing triggers for systemd (255.4-1ubuntu7) ... 1149s Processing triggers for man-db (2.12.0-4build1) ... 1150s Processing triggers for debianutils (5.17build1) ... 1151s Reading package lists... 1151s Building dependency tree... 1151s Reading state information... 1151s The following packages will be REMOVED: 1151s linux-headers-6.8.0-11* linux-headers-6.8.0-11-generic* 1151s linux-image-6.8.0-11-generic* linux-modules-6.8.0-11-generic* 1152s 0 upgraded, 0 newly installed, 4 to remove and 0 not upgraded. 1152s After this operation, 167 MB disk space will be freed. 1152s (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 ... 105901 files and directories currently installed.) 1152s Removing linux-headers-6.8.0-11-generic (6.8.0-11.11) ... 1152s Removing linux-headers-6.8.0-11 (6.8.0-11.11) ... 1154s Removing linux-image-6.8.0-11-generic (6.8.0-11.11) ... 1154s I: /boot/vmlinuz.old is now a symlink to vmlinuz-6.8.0-22-generic 1154s I: /boot/initrd.img.old is now a symlink to initrd.img-6.8.0-22-generic 1154s /etc/kernel/postrm.d/initramfs-tools: 1154s update-initramfs: Deleting /boot/initrd.img-6.8.0-11-generic 1155s /etc/kernel/postrm.d/zz-update-grub: 1155s Sourcing file `/etc/default/grub' 1155s Sourcing file `/etc/default/grub.d/50-cloudimg-settings.cfg' 1155s Sourcing file `/etc/default/grub.d/90-autopkgtest.cfg' 1155s Generating grub configuration file ... 1155s Found linux image: /boot/vmlinuz-6.8.0-22-generic 1155s Found initrd image: /boot/initrd.img-6.8.0-22-generic 1155s Warning: os-prober will not be executed to detect other bootable partitions. 1155s Systems on them will not be added to the GRUB boot configuration. 1155s Check GRUB_DISABLE_OS_PROBER documentation entry. 1155s Adding boot menu entry for UEFI Firmware Settings ... 1155s done 1155s Removing linux-modules-6.8.0-11-generic (6.8.0-11.11) ... 1155s (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 ... 74382 files and directories currently installed.) 1155s Purging configuration files for linux-image-6.8.0-11-generic (6.8.0-11.11) ... 1155s Purging configuration files for linux-modules-6.8.0-11-generic (6.8.0-11.11) ... 1156s Hit:1 http://ftpmaster.internal/ubuntu noble-proposed InRelease 1156s Hit:2 http://ftpmaster.internal/ubuntu noble InRelease 1156s Hit:3 http://ftpmaster.internal/ubuntu noble-updates InRelease 1156s Hit:4 http://ftpmaster.internal/ubuntu noble-security InRelease 1157s Reading package lists... 1157s Reading package lists... 1157s Building dependency tree... 1157s Reading state information... 1158s Calculating upgrade... 1158s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 1158s Reading package lists... 1158s Building dependency tree... 1158s Reading state information... 1159s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 1159s autopkgtest [21:48:27]: rebooting testbed after setup commands that affected boot 1181s autopkgtest-virt-ssh: WARNING: ssh connection failed. Retrying in 3 seconds... 1185s autopkgtest [21:48:53]: testbed running kernel: Linux 6.8.0-22-generic #22-Ubuntu SMP PREEMPT_DYNAMIC Thu Apr 4 22:30:32 UTC 2024 1186s autopkgtest [21:48:54]: @@@@@@@@@@@@@@@@@@@@ apt-source asterisk 1189s Get:1 http://ftpmaster.internal/ubuntu noble/universe asterisk 1:20.6.0~dfsg+~cs6.13.40431414-2build4 (dsc) [5473 B] 1189s Get:2 http://ftpmaster.internal/ubuntu noble/universe asterisk 1:20.6.0~dfsg+~cs6.13.40431414-2build4 (tar) [11.3 kB] 1189s Get:3 http://ftpmaster.internal/ubuntu noble/universe asterisk 1:20.6.0~dfsg+~cs6.13.40431414-2build4 (tar) [21.9 kB] 1189s Get:4 http://ftpmaster.internal/ubuntu noble/universe asterisk 1:20.6.0~dfsg+~cs6.13.40431414-2build4 (tar) [22.5 kB] 1189s Get:5 http://ftpmaster.internal/ubuntu noble/universe asterisk 1:20.6.0~dfsg+~cs6.13.40431414-2build4 (tar) [5841 kB] 1189s Get:6 http://ftpmaster.internal/ubuntu noble/universe asterisk 1:20.6.0~dfsg+~cs6.13.40431414-2build4 (tar) [7300 kB] 1189s Get:7 http://ftpmaster.internal/ubuntu noble/universe asterisk 1:20.6.0~dfsg+~cs6.13.40431414-2build4 (diff) [135 kB] 1189s gpgv: Signature made Sun Mar 31 00:19:33 2024 UTC 1189s gpgv: using RSA key AC483F68DE728F43F2202FCA568D30F321B2133D 1189s gpgv: issuer "steve.langasek@ubuntu.com" 1189s gpgv: Can't check signature: No public key 1189s dpkg-source: warning: cannot verify inline signature for ./asterisk_20.6.0~dfsg+~cs6.13.40431414-2build4.dsc: no acceptable signature found 1190s autopkgtest [21:48:58]: testing package asterisk version 1:20.6.0~dfsg+~cs6.13.40431414-2build4 1190s autopkgtest [21:48:58]: build not needed 1191s autopkgtest [21:48:59]: test asttestmods: preparing testbed 1196s Reading package lists... 1196s Building dependency tree... 1196s Reading state information... 1196s Starting pkgProblemResolver with broken count: 0 1196s Starting 2 pkgProblemResolver with broken count: 0 1196s Done 1197s The following additional packages will be installed: 1197s asterisk asterisk-config asterisk-core-sounds-en asterisk-core-sounds-en-gsm 1197s asterisk-modules asterisk-tests freetds-common libasound2-data libasound2t64 1197s libc-client2007e libcodec2-1.2 libevent-2.1-7t64 libgmime-3.0-0t64 libgsm1 1197s libical3t64 libiksemel3 libjack-jackd2-0 libltdl7 liblua5.1-0 libneon27t64 1197s libodbc2 libogg0 libopencore-amrnb0 libopencore-amrwb0 libopus0 libopusenc0 1197s libopusfile0 libportaudio2 libpq5 libradcli4 libresample1 libsamplerate0 1197s libsnmp-base libsnmp40t64 libspandsp2t64 libspeex1 libspeexdsp1 libsrtp2-1 1197s libsybdb5 libunbound8 liburiparser1 libvo-amrwbenc0 libvorbis0a 1197s libvorbisenc2 libvorbisfile3 libxml2-utils libxslt1.1 mlock 1197s Suggested packages: 1197s asterisk-dahdi asterisk-dev asterisk-doc asterisk-ooh323 asterisk-opus 1197s alsa-utils libasound2-plugins uw-mailutils jackd2 odbc-postgresql tdsodbc 1197s opus-tools snmp-mibs-downloader speex 1197s Recommended packages: 1197s asterisk-moh-opsound-gsm sox alsa-ucm-conf alsa-topology-conf 1197s The following NEW packages will be installed: 1197s asterisk asterisk-config asterisk-core-sounds-en asterisk-core-sounds-en-gsm 1197s asterisk-modules asterisk-tests autopkgtest-satdep freetds-common 1197s libasound2-data libasound2t64 libc-client2007e libcodec2-1.2 1197s libevent-2.1-7t64 libgmime-3.0-0t64 libgsm1 libical3t64 libiksemel3 1197s libjack-jackd2-0 libltdl7 liblua5.1-0 libneon27t64 libodbc2 libogg0 1197s libopencore-amrnb0 libopencore-amrwb0 libopus0 libopusenc0 libopusfile0 1197s libportaudio2 libpq5 libradcli4 libresample1 libsamplerate0 libsnmp-base 1197s libsnmp40t64 libspandsp2t64 libspeex1 libspeexdsp1 libsrtp2-1 libsybdb5 1197s libunbound8 liburiparser1 libvo-amrwbenc0 libvorbis0a libvorbisenc2 1197s libvorbisfile3 libxml2-utils libxslt1.1 mlock 1197s 0 upgraded, 49 newly installed, 0 to remove and 0 not upgraded. 1197s Need to get 25.4 MB/25.4 MB of archives. 1197s After this operation, 68.0 MB of additional disk space will be used. 1197s Get:1 /tmp/autopkgtest.VZH8Xz/1-autopkgtest-satdep.deb autopkgtest-satdep amd64 0 [736 B] 1197s Get:2 http://ftpmaster.internal/ubuntu noble/universe amd64 asterisk-config all 1:20.6.0~dfsg+~cs6.13.40431414-2build4 [242 kB] 1197s Get:3 http://ftpmaster.internal/ubuntu noble/universe amd64 asterisk-core-sounds-en-gsm all 1.6.1-1 [2417 kB] 1197s Get:4 http://ftpmaster.internal/ubuntu noble/universe amd64 asterisk-core-sounds-en all 1.6.1-1 [20.6 kB] 1197s Get:5 http://ftpmaster.internal/ubuntu noble-updates/universe amd64 mlock amd64 8:2007f~dfsg-7build1 [12.2 kB] 1197s Get:6 http://ftpmaster.internal/ubuntu noble-updates/universe amd64 libc-client2007e amd64 8:2007f~dfsg-7build1 [645 kB] 1197s Get:7 http://ftpmaster.internal/ubuntu noble/universe amd64 libcodec2-1.2 amd64 1.2.0-2 [8999 kB] 1197s Get:8 http://ftpmaster.internal/ubuntu noble/universe amd64 libgmime-3.0-0t64 amd64 3.2.13+dfsg-2.1build2 [176 kB] 1197s Get:9 http://ftpmaster.internal/ubuntu noble/universe amd64 libgsm1 amd64 1.0.22-1 [27.9 kB] 1197s Get:10 http://ftpmaster.internal/ubuntu noble/main amd64 libical3t64 amd64 3.0.17-1.1build3 [305 kB] 1197s Get:11 http://ftpmaster.internal/ubuntu noble/universe amd64 libiksemel3 amd64 1.4-4build2 [28.0 kB] 1197s Get:12 http://ftpmaster.internal/ubuntu noble/main amd64 libopus0 amd64 1.4-1 [208 kB] 1197s Get:13 http://ftpmaster.internal/ubuntu noble/main amd64 libsamplerate0 amd64 0.2.2-4 [1343 kB] 1197s Get:14 http://ftpmaster.internal/ubuntu noble/main amd64 libjack-jackd2-0 amd64 1.9.21~dfsg-3ubuntu3 [289 kB] 1197s Get:15 http://ftpmaster.internal/ubuntu noble/universe amd64 liblua5.1-0 amd64 5.1.5-9build2 [120 kB] 1197s Get:16 http://ftpmaster.internal/ubuntu noble/universe amd64 libneon27t64 amd64 0.33.0-1.1build2 [102 kB] 1197s Get:17 http://ftpmaster.internal/ubuntu noble/main amd64 libltdl7 amd64 2.4.7-7 [40.5 kB] 1197s Get:18 http://ftpmaster.internal/ubuntu noble/main amd64 libodbc2 amd64 2.3.12-1build2 [158 kB] 1197s Get:19 http://ftpmaster.internal/ubuntu noble/main amd64 libogg0 amd64 1.3.5-3 [22.4 kB] 1197s Get:20 http://ftpmaster.internal/ubuntu noble/universe amd64 libopencore-amrnb0 amd64 0.1.6-1 [97.9 kB] 1197s Get:21 http://ftpmaster.internal/ubuntu noble/universe amd64 libopencore-amrwb0 amd64 0.1.6-1 [53.0 kB] 1197s Get:22 http://ftpmaster.internal/ubuntu noble/universe amd64 libopusenc0 amd64 0.2.1-2 [25.2 kB] 1197s Get:23 http://ftpmaster.internal/ubuntu noble/universe amd64 libopusfile0 amd64 0.12-4build2 [44.7 kB] 1197s Get:24 http://ftpmaster.internal/ubuntu noble/main amd64 libasound2-data all 1.2.11-1build2 [21.0 kB] 1197s Get:25 http://ftpmaster.internal/ubuntu noble/main amd64 libasound2t64 amd64 1.2.11-1build2 [399 kB] 1197s Get:26 http://ftpmaster.internal/ubuntu noble/universe amd64 libportaudio2 amd64 19.6.0-1.2build3 [67.9 kB] 1197s Get:27 http://ftpmaster.internal/ubuntu noble/main amd64 libpq5 amd64 16.2-1ubuntu3 [138 kB] 1197s Get:28 http://ftpmaster.internal/ubuntu noble/universe amd64 libradcli4 amd64 1.2.11-1build3 [40.5 kB] 1197s Get:29 http://ftpmaster.internal/ubuntu noble/universe amd64 libresample1 amd64 0.1.3-6 [8806 B] 1197s Get:30 http://ftpmaster.internal/ubuntu noble/main amd64 libsnmp-base all 5.9.4+dfsg-1.1ubuntu3 [206 kB] 1197s Get:31 http://ftpmaster.internal/ubuntu noble/main amd64 libsnmp40t64 amd64 5.9.4+dfsg-1.1ubuntu3 [1066 kB] 1197s Get:32 http://ftpmaster.internal/ubuntu noble/universe amd64 libspandsp2t64 amd64 0.0.6+dfsg-2.1build1 [311 kB] 1197s Get:33 http://ftpmaster.internal/ubuntu noble/main amd64 libspeex1 amd64 1.2.1-2ubuntu1 [58.8 kB] 1197s Get:34 http://ftpmaster.internal/ubuntu noble/main amd64 libspeexdsp1 amd64 1.2.1-1ubuntu3 [43.1 kB] 1197s Get:35 http://ftpmaster.internal/ubuntu noble/universe amd64 libsrtp2-1 amd64 2.5.0-3 [41.3 kB] 1197s Get:36 http://ftpmaster.internal/ubuntu noble/main amd64 freetds-common all 1.3.17+ds-2build3 [26.9 kB] 1197s Get:37 http://ftpmaster.internal/ubuntu noble/main amd64 libsybdb5 amd64 1.3.17+ds-2build3 [192 kB] 1197s Get:38 http://ftpmaster.internal/ubuntu noble/main amd64 libevent-2.1-7t64 amd64 2.1.12-stable-9ubuntu2 [145 kB] 1197s Get:39 http://ftpmaster.internal/ubuntu noble/main amd64 libunbound8 amd64 1.19.2-1ubuntu3 [440 kB] 1197s Get:40 http://ftpmaster.internal/ubuntu noble/universe amd64 libvo-amrwbenc0 amd64 0.1.3-2 [68.2 kB] 1197s Get:41 http://ftpmaster.internal/ubuntu noble/main amd64 libvorbis0a amd64 1.3.7-1build2 [99.2 kB] 1197s Get:42 http://ftpmaster.internal/ubuntu noble/main amd64 libvorbisenc2 amd64 1.3.7-1build2 [82.6 kB] 1197s Get:43 http://ftpmaster.internal/ubuntu noble/main amd64 libvorbisfile3 amd64 1.3.7-1build2 [17.1 kB] 1197s Get:44 http://ftpmaster.internal/ubuntu noble/universe amd64 asterisk-modules amd64 1:20.6.0~dfsg+~cs6.13.40431414-2build4 [3177 kB] 1197s Get:45 http://ftpmaster.internal/ubuntu noble/universe amd64 liburiparser1 amd64 0.9.7+dfsg-2 [35.9 kB] 1197s Get:46 http://ftpmaster.internal/ubuntu noble/main amd64 libxslt1.1 amd64 1.1.39-0exp1build1 [167 kB] 1197s Get:47 http://ftpmaster.internal/ubuntu noble/universe amd64 asterisk amd64 1:20.6.0~dfsg+~cs6.13.40431414-2build4 [2601 kB] 1197s Get:48 http://ftpmaster.internal/ubuntu noble/universe amd64 asterisk-tests amd64 1:20.6.0~dfsg+~cs6.13.40431414-2build4 [548 kB] 1197s Get:49 http://ftpmaster.internal/ubuntu noble/main amd64 libxml2-utils amd64 2.9.14+dfsg-1.3ubuntu3 [39.4 kB] 1197s Fetched 25.4 MB in 0s (91.3 MB/s) 1197s Selecting previously unselected package asterisk-config. 1198s (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 ... 74381 files and directories currently installed.) 1198s Preparing to unpack .../00-asterisk-config_1%3a20.6.0~dfsg+~cs6.13.40431414-2build4_all.deb ... 1198s Unpacking asterisk-config (1:20.6.0~dfsg+~cs6.13.40431414-2build4) ... 1198s Selecting previously unselected package asterisk-core-sounds-en-gsm. 1198s Preparing to unpack .../01-asterisk-core-sounds-en-gsm_1.6.1-1_all.deb ... 1198s Unpacking asterisk-core-sounds-en-gsm (1.6.1-1) ... 1198s Selecting previously unselected package asterisk-core-sounds-en. 1198s Preparing to unpack .../02-asterisk-core-sounds-en_1.6.1-1_all.deb ... 1198s Unpacking asterisk-core-sounds-en (1.6.1-1) ... 1198s Selecting previously unselected package mlock. 1198s Preparing to unpack .../03-mlock_8%3a2007f~dfsg-7build1_amd64.deb ... 1198s Unpacking mlock (8:2007f~dfsg-7build1) ... 1198s Selecting previously unselected package libc-client2007e. 1198s Preparing to unpack .../04-libc-client2007e_8%3a2007f~dfsg-7build1_amd64.deb ... 1198s Unpacking libc-client2007e (8:2007f~dfsg-7build1) ... 1198s Selecting previously unselected package libcodec2-1.2:amd64. 1198s Preparing to unpack .../05-libcodec2-1.2_1.2.0-2_amd64.deb ... 1198s Unpacking libcodec2-1.2:amd64 (1.2.0-2) ... 1198s Selecting previously unselected package libgmime-3.0-0t64:amd64. 1198s Preparing to unpack .../06-libgmime-3.0-0t64_3.2.13+dfsg-2.1build2_amd64.deb ... 1198s Unpacking libgmime-3.0-0t64:amd64 (3.2.13+dfsg-2.1build2) ... 1198s Selecting previously unselected package libgsm1:amd64. 1198s Preparing to unpack .../07-libgsm1_1.0.22-1_amd64.deb ... 1198s Unpacking libgsm1:amd64 (1.0.22-1) ... 1198s Selecting previously unselected package libical3t64:amd64. 1198s Preparing to unpack .../08-libical3t64_3.0.17-1.1build3_amd64.deb ... 1198s Unpacking libical3t64:amd64 (3.0.17-1.1build3) ... 1198s Selecting previously unselected package libiksemel3:amd64. 1198s Preparing to unpack .../09-libiksemel3_1.4-4build2_amd64.deb ... 1198s Unpacking libiksemel3:amd64 (1.4-4build2) ... 1198s Selecting previously unselected package libopus0:amd64. 1198s Preparing to unpack .../10-libopus0_1.4-1_amd64.deb ... 1198s Unpacking libopus0:amd64 (1.4-1) ... 1198s Selecting previously unselected package libsamplerate0:amd64. 1198s Preparing to unpack .../11-libsamplerate0_0.2.2-4_amd64.deb ... 1198s Unpacking libsamplerate0:amd64 (0.2.2-4) ... 1198s Selecting previously unselected package libjack-jackd2-0:amd64. 1198s Preparing to unpack .../12-libjack-jackd2-0_1.9.21~dfsg-3ubuntu3_amd64.deb ... 1198s Unpacking libjack-jackd2-0:amd64 (1.9.21~dfsg-3ubuntu3) ... 1198s Selecting previously unselected package liblua5.1-0:amd64. 1198s Preparing to unpack .../13-liblua5.1-0_5.1.5-9build2_amd64.deb ... 1198s Unpacking liblua5.1-0:amd64 (5.1.5-9build2) ... 1198s Selecting previously unselected package libneon27t64:amd64. 1198s Preparing to unpack .../14-libneon27t64_0.33.0-1.1build2_amd64.deb ... 1198s Unpacking libneon27t64:amd64 (0.33.0-1.1build2) ... 1198s Selecting previously unselected package libltdl7:amd64. 1198s Preparing to unpack .../15-libltdl7_2.4.7-7_amd64.deb ... 1198s Unpacking libltdl7:amd64 (2.4.7-7) ... 1198s Selecting previously unselected package libodbc2:amd64. 1198s Preparing to unpack .../16-libodbc2_2.3.12-1build2_amd64.deb ... 1198s Unpacking libodbc2:amd64 (2.3.12-1build2) ... 1198s Selecting previously unselected package libogg0:amd64. 1198s Preparing to unpack .../17-libogg0_1.3.5-3_amd64.deb ... 1198s Unpacking libogg0:amd64 (1.3.5-3) ... 1198s Selecting previously unselected package libopencore-amrnb0:amd64. 1198s Preparing to unpack .../18-libopencore-amrnb0_0.1.6-1_amd64.deb ... 1198s Unpacking libopencore-amrnb0:amd64 (0.1.6-1) ... 1199s Selecting previously unselected package libopencore-amrwb0:amd64. 1199s Preparing to unpack .../19-libopencore-amrwb0_0.1.6-1_amd64.deb ... 1199s Unpacking libopencore-amrwb0:amd64 (0.1.6-1) ... 1199s Selecting previously unselected package libopusenc0:amd64. 1199s Preparing to unpack .../20-libopusenc0_0.2.1-2_amd64.deb ... 1199s Unpacking libopusenc0:amd64 (0.2.1-2) ... 1199s Selecting previously unselected package libopusfile0:amd64. 1199s Preparing to unpack .../21-libopusfile0_0.12-4build2_amd64.deb ... 1199s Unpacking libopusfile0:amd64 (0.12-4build2) ... 1199s Selecting previously unselected package libasound2-data. 1199s Preparing to unpack .../22-libasound2-data_1.2.11-1build2_all.deb ... 1199s Unpacking libasound2-data (1.2.11-1build2) ... 1199s Selecting previously unselected package libasound2t64:amd64. 1199s Preparing to unpack .../23-libasound2t64_1.2.11-1build2_amd64.deb ... 1199s Unpacking libasound2t64:amd64 (1.2.11-1build2) ... 1199s Selecting previously unselected package libportaudio2:amd64. 1199s Preparing to unpack .../24-libportaudio2_19.6.0-1.2build3_amd64.deb ... 1199s Unpacking libportaudio2:amd64 (19.6.0-1.2build3) ... 1199s Selecting previously unselected package libpq5:amd64. 1199s Preparing to unpack .../25-libpq5_16.2-1ubuntu3_amd64.deb ... 1199s Unpacking libpq5:amd64 (16.2-1ubuntu3) ... 1199s Selecting previously unselected package libradcli4. 1199s Preparing to unpack .../26-libradcli4_1.2.11-1build3_amd64.deb ... 1199s Unpacking libradcli4 (1.2.11-1build3) ... 1199s Selecting previously unselected package libresample1. 1199s Preparing to unpack .../27-libresample1_0.1.3-6_amd64.deb ... 1199s Unpacking libresample1 (0.1.3-6) ... 1199s Selecting previously unselected package libsnmp-base. 1199s Preparing to unpack .../28-libsnmp-base_5.9.4+dfsg-1.1ubuntu3_all.deb ... 1199s Unpacking libsnmp-base (5.9.4+dfsg-1.1ubuntu3) ... 1199s Selecting previously unselected package libsnmp40t64:amd64. 1199s Preparing to unpack .../29-libsnmp40t64_5.9.4+dfsg-1.1ubuntu3_amd64.deb ... 1199s Unpacking libsnmp40t64:amd64 (5.9.4+dfsg-1.1ubuntu3) ... 1199s Selecting previously unselected package libspandsp2t64:amd64. 1199s Preparing to unpack .../30-libspandsp2t64_0.0.6+dfsg-2.1build1_amd64.deb ... 1199s Unpacking libspandsp2t64:amd64 (0.0.6+dfsg-2.1build1) ... 1199s Selecting previously unselected package libspeex1:amd64. 1199s Preparing to unpack .../31-libspeex1_1.2.1-2ubuntu1_amd64.deb ... 1199s Unpacking libspeex1:amd64 (1.2.1-2ubuntu1) ... 1199s Selecting previously unselected package libspeexdsp1:amd64. 1199s Preparing to unpack .../32-libspeexdsp1_1.2.1-1ubuntu3_amd64.deb ... 1199s Unpacking libspeexdsp1:amd64 (1.2.1-1ubuntu3) ... 1199s Selecting previously unselected package libsrtp2-1:amd64. 1199s Preparing to unpack .../33-libsrtp2-1_2.5.0-3_amd64.deb ... 1199s Unpacking libsrtp2-1:amd64 (2.5.0-3) ... 1199s Selecting previously unselected package freetds-common. 1199s Preparing to unpack .../34-freetds-common_1.3.17+ds-2build3_all.deb ... 1199s Unpacking freetds-common (1.3.17+ds-2build3) ... 1199s Selecting previously unselected package libsybdb5:amd64. 1199s Preparing to unpack .../35-libsybdb5_1.3.17+ds-2build3_amd64.deb ... 1199s Unpacking libsybdb5:amd64 (1.3.17+ds-2build3) ... 1199s Selecting previously unselected package libevent-2.1-7t64:amd64. 1199s Preparing to unpack .../36-libevent-2.1-7t64_2.1.12-stable-9ubuntu2_amd64.deb ... 1199s Unpacking libevent-2.1-7t64:amd64 (2.1.12-stable-9ubuntu2) ... 1199s Selecting previously unselected package libunbound8:amd64. 1199s Preparing to unpack .../37-libunbound8_1.19.2-1ubuntu3_amd64.deb ... 1199s Unpacking libunbound8:amd64 (1.19.2-1ubuntu3) ... 1199s Selecting previously unselected package libvo-amrwbenc0:amd64. 1199s Preparing to unpack .../38-libvo-amrwbenc0_0.1.3-2_amd64.deb ... 1199s Unpacking libvo-amrwbenc0:amd64 (0.1.3-2) ... 1199s Selecting previously unselected package libvorbis0a:amd64. 1199s Preparing to unpack .../39-libvorbis0a_1.3.7-1build2_amd64.deb ... 1199s Unpacking libvorbis0a:amd64 (1.3.7-1build2) ... 1199s Selecting previously unselected package libvorbisenc2:amd64. 1199s Preparing to unpack .../40-libvorbisenc2_1.3.7-1build2_amd64.deb ... 1199s Unpacking libvorbisenc2:amd64 (1.3.7-1build2) ... 1199s Selecting previously unselected package libvorbisfile3:amd64. 1199s Preparing to unpack .../41-libvorbisfile3_1.3.7-1build2_amd64.deb ... 1199s Unpacking libvorbisfile3:amd64 (1.3.7-1build2) ... 1199s Selecting previously unselected package asterisk-modules. 1199s Preparing to unpack .../42-asterisk-modules_1%3a20.6.0~dfsg+~cs6.13.40431414-2build4_amd64.deb ... 1199s Unpacking asterisk-modules (1:20.6.0~dfsg+~cs6.13.40431414-2build4) ... 1199s Selecting previously unselected package liburiparser1:amd64. 1199s Preparing to unpack .../43-liburiparser1_0.9.7+dfsg-2_amd64.deb ... 1199s Unpacking liburiparser1:amd64 (0.9.7+dfsg-2) ... 1199s Selecting previously unselected package libxslt1.1:amd64. 1199s Preparing to unpack .../44-libxslt1.1_1.1.39-0exp1build1_amd64.deb ... 1199s Unpacking libxslt1.1:amd64 (1.1.39-0exp1build1) ... 1199s Selecting previously unselected package asterisk. 1199s Preparing to unpack .../45-asterisk_1%3a20.6.0~dfsg+~cs6.13.40431414-2build4_amd64.deb ... 1199s Unpacking asterisk (1:20.6.0~dfsg+~cs6.13.40431414-2build4) ... 1200s Selecting previously unselected package asterisk-tests. 1200s Preparing to unpack .../46-asterisk-tests_1%3a20.6.0~dfsg+~cs6.13.40431414-2build4_amd64.deb ... 1200s Unpacking asterisk-tests (1:20.6.0~dfsg+~cs6.13.40431414-2build4) ... 1200s Selecting previously unselected package libxml2-utils. 1200s Preparing to unpack .../47-libxml2-utils_2.9.14+dfsg-1.3ubuntu3_amd64.deb ... 1200s Unpacking libxml2-utils (2.9.14+dfsg-1.3ubuntu3) ... 1200s Selecting previously unselected package autopkgtest-satdep. 1200s Preparing to unpack .../48-1-autopkgtest-satdep.deb ... 1200s Unpacking autopkgtest-satdep (0) ... 1200s Setting up libvo-amrwbenc0:amd64 (0.1.3-2) ... 1200s Setting up libneon27t64:amd64 (0.33.0-1.1build2) ... 1200s Setting up libogg0:amd64 (1.3.5-3) ... 1200s Setting up libspeex1:amd64 (1.2.1-2ubuntu1) ... 1200s Setting up libgsm1:amd64 (1.0.22-1) ... 1200s Setting up asterisk-core-sounds-en-gsm (1.6.1-1) ... 1200s Setting up libsnmp-base (5.9.4+dfsg-1.1ubuntu3) ... 1200s Setting up libcodec2-1.2:amd64 (1.2.0-2) ... 1200s Setting up mlock (8:2007f~dfsg-7build1) ... 1200s Setting up libsrtp2-1:amd64 (2.5.0-3) ... 1200s Setting up libpq5:amd64 (16.2-1ubuntu3) ... 1200s Setting up libevent-2.1-7t64:amd64 (2.1.12-stable-9ubuntu2) ... 1200s Setting up libasound2-data (1.2.11-1build2) ... 1200s Setting up libopencore-amrwb0:amd64 (0.1.6-1) ... 1200s Setting up libunbound8:amd64 (1.19.2-1ubuntu3) ... 1200s Setting up libasound2t64:amd64 (1.2.11-1build2) ... 1200s Setting up libradcli4 (1.2.11-1build3) ... 1200s Setting up libopus0:amd64 (1.4-1) ... 1200s Setting up asterisk-config (1:20.6.0~dfsg+~cs6.13.40431414-2build4) ... 1200s Setting up libvorbis0a:amd64 (1.3.7-1build2) ... 1200s Setting up libical3t64:amd64 (3.0.17-1.1build3) ... 1200s Setting up libltdl7:amd64 (2.4.7-7) ... 1200s Setting up asterisk-core-sounds-en (1.6.1-1) ... 1200s update-alternatives: using /usr/share/asterisk/sounds/en_US_f_Allison to provide /usr/share/asterisk/sounds/en (asterisk-prompt-en) in auto mode 1200s 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 1200s Setting up libiksemel3:amd64 (1.4-4build2) ... 1200s Setting up libodbc2:amd64 (2.3.12-1build2) ... 1200s Setting up liburiparser1:amd64 (0.9.7+dfsg-2) ... 1200s Setting up libspandsp2t64:amd64 (0.0.6+dfsg-2.1build1) ... 1200s Setting up libspeexdsp1:amd64 (1.2.1-1ubuntu3) ... 1200s Setting up liblua5.1-0:amd64 (5.1.5-9build2) ... 1200s Setting up libxslt1.1:amd64 (1.1.39-0exp1build1) ... 1200s Setting up libopencore-amrnb0:amd64 (0.1.6-1) ... 1200s Setting up libc-client2007e (8:2007f~dfsg-7build1) ... 1200s Setting up libresample1 (0.1.3-6) ... 1200s Setting up freetds-common (1.3.17+ds-2build3) ... 1200s Setting up libxml2-utils (2.9.14+dfsg-1.3ubuntu3) ... 1200s Setting up libgmime-3.0-0t64:amd64 (3.2.13+dfsg-2.1build2) ... 1200s Setting up libsamplerate0:amd64 (0.2.2-4) ... 1200s Setting up libopusfile0:amd64 (0.12-4build2) ... 1200s Setting up libvorbisenc2:amd64 (1.3.7-1build2) ... 1200s Setting up libopusenc0:amd64 (0.2.1-2) ... 1200s Setting up libsnmp40t64:amd64 (5.9.4+dfsg-1.1ubuntu3) ... 1200s Setting up libsybdb5:amd64 (1.3.17+ds-2build3) ... 1200s Setting up libvorbisfile3:amd64 (1.3.7-1build2) ... 1200s Setting up libjack-jackd2-0:amd64 (1.9.21~dfsg-3ubuntu3) ... 1200s Setting up libportaudio2:amd64 (19.6.0-1.2build3) ... 1200s Setting up asterisk-modules (1:20.6.0~dfsg+~cs6.13.40431414-2build4) ... 1200s Setting up asterisk (1:20.6.0~dfsg+~cs6.13.40431414-2build4) ... 1200s Adding system user for Asterisk 1200s info: Adding user `asterisk' to group `dialout' ... 1200s info: Adding user `asterisk' to group `audio' ... 1201s Created symlink /etc/systemd/system/multi-user.target.wants/asterisk.service → /usr/lib/systemd/system/asterisk.service. 1202s Setting up asterisk-tests (1:20.6.0~dfsg+~cs6.13.40431414-2build4) ... 1202s Setting up autopkgtest-satdep (0) ... 1202s Processing triggers for man-db (2.12.0-4build1) ... 1203s Processing triggers for libc-bin (2.39-0ubuntu8) ... 1206s (Reading database ... 76412 files and directories currently installed.) 1206s Removing autopkgtest-satdep (0) ... 1207s autopkgtest [21:49:15]: test asttestmods: [----------------------- 1207s dpkg-architecture: warning: cannot determine CC system type, falling back to default (native compilation) 1209s 'U' option is not compatible with remote console mode and has no effect. 1209s 1209s Asterisk has fully booted. 1209s 'U' option is not compatible with remote console mode and has no effect. 1209s 1209s Running all available tests... 1209s 1209s START /apps/app_gosub/ - gosub application 1209s END /apps/app_gosub/ - gosub application Time: <1ms Result: PASS 1209s START /apps/app_voicemail/ - test_voicemail_vm_info 1209s END /apps/app_voicemail/ - test_voicemail_vm_info Time: <1ms Result: PASS 1209s START /apps/app_voicemail/ - test_voicemail_load_config 1209s END /apps/app_voicemail/ - test_voicemail_load_config Time: <1ms Result: PASS 1209s START /apps/app_voicemail/ - test_voicemail_notify_endl 1209s END /apps/app_voicemail/ - test_voicemail_notify_endl Time: 2ms Result: PASS 1209s START /apps/app_voicemail/ - vmuser 1209s END /apps/app_voicemail/ - vmuser Time: <1ms Result: PASS 1209s START /apps/app_voicemail/ - test_voicemail_msgcount 1209s END /apps/app_voicemail/ - test_voicemail_msgcount Time: 73ms Result: PASS 1209s START /apps/app_voicemail/ - vmsayname_exec 1209s [app_voicemail.c:test_voicemail_vmsayname:15218]: Test playing of extension when greeting is not available... 1213s [app_voicemail.c:test_voicemail_vmsayname:15239]: Test playing created mailbox greeting... 1218s END /apps/app_voicemail/ - vmsayname_exec Time: 8888ms Result: PASS 1218s START /ari/validators/ - validate_list 1218s END /ari/validators/ - validate_list Time: <1ms Result: PASS 1218s START /ari/validators/ - validate_date 1218s END /ari/validators/ - validate_date Time: <1ms Result: PASS 1218s START /ari/validators/ - validate_string 1218s END /ari/validators/ - validate_string Time: <1ms Result: PASS 1218s START /ari/validators/ - validate_long 1218s END /ari/validators/ - validate_long Time: <1ms Result: PASS 1218s START /ari/validators/ - validate_int 1218s END /ari/validators/ - validate_int Time: <1ms Result: PASS 1218s START /ari/validators/ - validate_boolean 1218s END /ari/validators/ - validate_boolean Time: <1ms Result: PASS 1218s START /ari/validators/ - validate_byte 1218s END /ari/validators/ - validate_byte Time: <1ms Result: PASS 1218s START /bridges/bridge_softmix/ - sfu_remove_destination_streams 1218s END /bridges/bridge_softmix/ - sfu_remove_destination_streams Time: <1ms Result: PASS 1218s START /bridges/bridge_softmix/ - sfu_append_source_streams 1218s END /bridges/bridge_softmix/ - sfu_append_source_streams Time: <1ms Result: PASS 1218s START /channels/features/ - test_features_channel_interval 1221s END /channels/features/ - test_features_channel_interval Time: 3002ms Result: PASS 1221s START /channels/features/ - test_features_channel_dtmf 1223s END /channels/features/ - test_features_channel_dtmf Time: 2006ms Result: PASS 1223s START /config/ - config_options_test 1223s END /config/ - config_options_test Time: <1ms Result: PASS 1223s START /config/ - ast_parse_arg 1223s END /config/ - ast_parse_arg Time: <1ms Result: PASS 1223s START /core/endpoints/ - setters 1223s END /core/endpoints/ - setters Time: <1ms Result: PASS 1223s START /core/endpoints/ - defaults 1223s END /core/endpoints/ - defaults Time: <1ms Result: PASS 1223s START /core/endpoints/ - create 1223s END /core/endpoints/ - create Time: <1ms Result: PASS 1223s START /funcs/func_curl/ - vulnerable_url 1223s END /funcs/func_curl/ - vulnerable_url Time: <1ms Result: PASS 1223s START /funcs/func_env/ - func_file 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,1)=a'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-9,1)=a'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,-8)=a'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-9,-8)=a'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,5,1)=b'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-4,1)=b'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,5,-3)=b'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-4,-3)=b'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,2)=c'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-9,2)=c'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,-7)=c'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-9,-7)=c'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,4,2)=d'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-5,2)=d'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,4,-3)=d'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-5,-3)=d'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,5)=e'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,5)='... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-4)=e'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-4)='... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,1)=fg'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,-8)=fg'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-9,1)=fg'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-9,-8)=fg'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,)=h'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,,,,)=h'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,,,l)=h'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,,,ld)=h'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,1,l)=abc'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,1,l)=abc'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,-2,l)=abc'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,-2,l)=abc'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,1,l)=abc'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,-1,l)=abc'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,1,l)=abc'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,-1,l)=abc'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,1,l)=ab'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,1,l)=ab'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,-2,l)=ab'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,-2,l)=ab'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,1,l)=ab'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,-1,l)=ab'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,1,l)=ab'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,-1,l)=ab'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,1,l)=abcd'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,1,l)=abcd'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,-2,l)=abcd'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,-2,l)=abcd'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,1,l)=abcd'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,-1,l)=abcd'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,1,l)=abcd'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,-1,l)=abcd'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,2,l)=abcdefg'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,2,l)=abcdefg'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,-1,l)=abcdefg'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,-1,l)=abcdefg'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,2,l)=abcdefg'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,,l)=abcdefg'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,2,l)=abcdefg'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,,l)=abcdefg'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,2,l)=abcd'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,2,l)=abcd'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,-1,l)=abcd'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,-1,l)=abcd'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,2,l)=abcd'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,,l)=abcd'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,2,l)=abcd'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,,l)=abcd'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,2,l)=abcdefghijklmnop'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,2,l)=abcdefghijklmnop'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,-1,l)=abcdefghijklmnop'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,-1,l)=abcdefghijklmnop'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,2,l)=abcdefghijklmnop'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,,l)=abcdefghijklmnop'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,2,l)=abcdefghijklmnop'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,,l)=abcdefghijklmnop'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,0,l)=abcd'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,0,l)=abcd'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,0,l)=abcd'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,0,l)=abcd'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,2,0,l)=abcd'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-1,0,l)=abcd'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,3,0,l)=abcd'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,,,la)=abcd'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,1,l)='... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,1,l)='... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,-2,l)='... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,-2,l)='... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,1,l)='... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,-1,l)='... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,1,l)='... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,-1,l)='... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,1,ld)='... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,1,ld)='... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,-2,ld)='... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,-2,ld)='... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,1,ld)='... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,-1,ld)='... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,1,ld)='... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,-1,ld)='... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,1)=a'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,1)=abcd'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,10)=abcd'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,1,l)=abcd'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,1,l)=abcd'... OK! 1223s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,1,l)=a'... OK! 1223s END /funcs/func_env/ - func_file Time: 29ms Result: PASS 1223s START /funcs/func_json/ - func_JSON_DECODE 1223s END /funcs/func_json/ - func_JSON_DECODE Time: <1ms Result: PASS 1223s START /funcs/func_presence/ - test_presence_state_base64_encode 1223s END /funcs/func_presence/ - test_presence_state_base64_encode Time: 11ms Result: PASS 1223s START /funcs/func_presence/ - test_presence_state_change 1223s END /funcs/func_presence/ - test_presence_state_change Time: <1ms Result: PASS 1223s START /funcs/func_presence/ - parse_invalid_presence_data 1223s END /funcs/func_presence/ - parse_invalid_presence_data Time: <1ms Result: PASS 1223s START /funcs/func_presence/ - parse_valid_presence_data 1223s END /funcs/func_presence/ - parse_valid_presence_data Time: <1ms Result: PASS 1223s START /funcs/func_sayfiles/ - test_SAYFILES_function 1223s [func_sayfiles.c:test_SAYFILES_function:180]: Testing SAYFILES() substitution ... 1223s END /funcs/func_sayfiles/ - test_SAYFILES_function Time: 9ms Result: PASS 1223s START /funcs/func_strings/ - func_TRIM 1223s END /funcs/func_strings/ - func_TRIM Time: <1ms Result: PASS 1223s START /funcs/func_strings/ - func_STRBETWEEN 1223s END /funcs/func_strings/ - func_STRBETWEEN Time: <1ms Result: PASS 1223s START /funcs/func_strings/ - func_STRREPLACE_test 1223s END /funcs/func_strings/ - func_STRREPLACE_test Time: <1ms Result: PASS 1223s START /funcs/func_strings/ - func_FILTER_test 1223s END /funcs/func_strings/ - func_FILTER_test Time: <1ms Result: PASS 1223s START /funcs/func_strings/ - func_REPLACE_test 1223s END /funcs/func_strings/ - func_REPLACE_test Time: <1ms Result: PASS 1223s START /funcs/func_strings/ - func_FIELDNUM_test 1223s END /funcs/func_strings/ - func_FIELDNUM_test Time: <1ms Result: PASS 1223s START /geoloc/ - create_from_pidf 1223s [res_geolocation/geoloc_eprofile.c:validate_eprofile:1274]: ID: 'point-2d' pidf_element: 'tuple' format: 'GML' method: 'Manual' 1223s [res_geolocation/geoloc_eprofile.c:validate_eprofile:1286]: location_vars expected: shape=Point,crs=2d,pos=-34.410649 150.87651 1223s [res_geolocation/geoloc_eprofile.c:validate_eprofile:1287]: location_vars received: shape=Point,crs=2d,pos=-34.410649 150.87651 1223s [res_geolocation/geoloc_eprofile.c:validate_eprofile:1293]: usage_rules expected: retransmission-allowed='no',retention-expiry='2010-11-14T20:00:00Z' 1223s [res_geolocation/geoloc_eprofile.c:validate_eprofile:1294]: usage_rules received: retransmission-allowed='no',retention-expiry='2010-11-14T20:00:00Z' 1223s END /geoloc/ - create_from_pidf Time: <1ms Result: PASS 1223s START /geoloc/ - create_from_uri 1223s END /geoloc/ - create_from_uri Time: <1ms Result: PASS 1223s START /main/abstract_jb/ - AST_JB_FIXED_put_out_of_order 1223s [test_abstract_jb.c:AST_JB_FIXED_put_out_of_order:531]: Executing AST_JB_FIXED_put_out_of_order... 1223s END /main/abstract_jb/ - AST_JB_FIXED_put_out_of_order Time: <1ms Result: PASS 1223s START /main/abstract_jb/ - AST_JB_FIXED_put_overflow 1223s [test_abstract_jb.c:AST_JB_FIXED_put_overflow:529]: Executing AST_JB_FIXED_put_overflow... 1223s END /main/abstract_jb/ - AST_JB_FIXED_put_overflow Time: <1ms Result: PASS 1223s START /main/abstract_jb/ - AST_JB_FIXED_put 1223s [test_abstract_jb.c:AST_JB_FIXED_put:527]: Executing AST_JB_FIXED_put... 1223s END /main/abstract_jb/ - AST_JB_FIXED_put Time: <1ms Result: PASS 1223s START /main/abstract_jb/ - AST_JB_FIXED_put_first 1223s [test_abstract_jb.c:AST_JB_FIXED_put_first:525]: Executing AST_JB_FIXED_create... 1223s END /main/abstract_jb/ - AST_JB_FIXED_put_first Time: <1ms Result: PASS 1223s START /main/abstract_jb/ - AST_JB_FIXED_create 1223s [test_abstract_jb.c:AST_JB_FIXED_create:523]: Executing AST_JB_FIXED_create... 1223s END /main/abstract_jb/ - AST_JB_FIXED_create Time: <1ms Result: PASS 1223s START /main/abstract_jb/ - AST_JB_ADAPTIVE_put_out_of_order 1223s [test_abstract_jb.c:AST_JB_ADAPTIVE_put_out_of_order:521]: Executing AST_JB_ADAPTIVE_put_out_of_order... 1223s END /main/abstract_jb/ - AST_JB_ADAPTIVE_put_out_of_order Time: <1ms Result: PASS 1223s START /main/abstract_jb/ - AST_JB_ADAPTIVE_put_overflow 1223s [test_abstract_jb.c:AST_JB_ADAPTIVE_put_overflow:519]: Executing AST_JB_ADAPTIVE_put_overflow... 1223s END /main/abstract_jb/ - AST_JB_ADAPTIVE_put_overflow Time: <1ms Result: PASS 1223s START /main/abstract_jb/ - AST_JB_ADAPTIVE_put 1223s [test_abstract_jb.c:AST_JB_ADAPTIVE_put:517]: Executing AST_JB_ADAPTIVE_put... 1223s END /main/abstract_jb/ - AST_JB_ADAPTIVE_put Time: <1ms Result: PASS 1223s START /main/abstract_jb/ - AST_JB_ADAPTIVE_put_first 1223s [test_abstract_jb.c:AST_JB_ADAPTIVE_put_first:515]: Executing AST_JB_ADAPTIVE_create... 1223s END /main/abstract_jb/ - AST_JB_ADAPTIVE_put_first Time: <1ms Result: PASS 1223s START /main/abstract_jb/ - AST_JB_ADAPTIVE_create 1223s [test_abstract_jb.c:AST_JB_ADAPTIVE_create:513]: Executing AST_JB_ADAPTIVE_create... 1223s END /main/abstract_jb/ - AST_JB_ADAPTIVE_create Time: <1ms Result: PASS 1223s START /main/acl/ - acl 1223s END /main/acl/ - acl Time: <1ms Result: PASS 1223s START /main/acl/ - invalid_acl 1223s END /main/acl/ - invalid_acl Time: <1ms Result: PASS 1223s START /main/amihooks/ - amihook_cli_send 1223s END /main/amihooks/ - amihook_cli_send Time: <1ms Result: PASS 1223s START /main/aoc/ - aoc_event_test 1223s END /main/aoc/ - aoc_event_test Time: <1ms Result: PASS 1223s START /main/aoc/ - aoc_encode_decode_test 1223s END /main/aoc/ - aoc_encode_decode_test Time: <1ms Result: PASS 1223s START /main/app/ - options_parsing 1223s END /main/app/ - options_parsing Time: <1ms Result: PASS 1223s START /main/app/ - app_group 1223s [test_app.c:app_group:172]: Creating test channels with the following groups: 1223s 'a groupgroupgroup', 'a groupGroupgroup', 'a group@a_category', 'a group@another!Category' 1223s [test_app.c:app_group:211]: (Subtest 1) Found 4 matches as expected when examining group:'gr' category:'' 1223s [test_app.c:app_group:211]: (Subtest 2) Found 1 matches as expected when examining group:'(group){2}$' category:'' 1223s [test_app.c:app_group:211]: (Subtest 3) Found 4 matches as expected when examining group:'[:ascii:]' category:'' 1223s [test_app.c:app_group:211]: (Subtest 4) Found 0 matches as expected when examining group:'^(NOMATCH)' category:'' 1223s [test_app.c:app_group:211]: (Subtest 5) Found 2 matches as expected when examining group:'a group' category:'(gory)$' 1223s [test_app.c:app_group:211]: (Subtest 6) Found 1 matches as expected when examining group:'a group' category:'[A-Z]+' 1223s [test_app.c:app_group:211]: (Subtest 7) Found 0 matches as expected when examining group:'a group' category:'[[' 1223s END /main/app/ - app_group Time: <1ms Result: PASS 1223s START /main/ast_expr/ - expr_test 1223s END /main/ast_expr/ - expr_test Time: <1ms Result: PASS 1223s START /main/astdb/ - put_get_long 1223s END /main/astdb/ - put_get_long Time: 91ms Result: PASS 1223s START /main/astdb/ - perftest 1223s END /main/astdb/ - perftest Time: 256ms Result: PASS 1223s START /main/astdb/ - gettree_deltree 1223s END /main/astdb/ - gettree_deltree Time: <1ms Result: PASS 1223s START /main/astdb/ - put_get_del 1223s END /main/astdb/ - put_get_del Time: <1ms Result: PASS 1223s START /main/astobj2/ - astobj2_test4 1223s [test_astobj2.c:test_traversal_nonsorted:1389]: Test 1, List containers. 1223s [test_astobj2.c:test_traversal_nonsorted:1389]: Test 2, Hash containers. 1223s [test_astobj2.c:test_traversal_sorted:1615]: Test 3, List containers. 1223s [test_astobj2.c:test_traversal_sorted:1615]: Test 4, Hash containers. 1223s [test_astobj2.c:test_traversal_sorted:1615]: Test 5, RBTree containers. 1223s END /main/astobj2/ - astobj2_test4 Time: <1ms Result: PASS 1223s START /main/astobj2/ - astobj2_test3 1223s END /main/astobj2/ - astobj2_test3 Time: <1ms Result: PASS 1223s START /main/astobj2/ - astobj2_test2 1223s END /main/astobj2/ - astobj2_test2 Time: <1ms Result: PASS 1223s START /main/astobj2/ - astobj2_test1 1223s [test_astobj2.c:astobj2_test_1_helper:434]: Test 1, List containers (non-sorted). 1223s [test_astobj2.c:astobj2_test_1_helper:488]: List container created: buckets: 1, items: 50 1223s [test_astobj2.c:astobj2_test_1_helper:434]: Test 2, List containers (sorted). 1223s [test_astobj2.c:astobj2_test_1_helper:488]: List container created: buckets: 1, items: 50 1223s [test_astobj2.c:astobj2_test_1_helper:434]: Test 3, Hash containers (non-sorted). 1223s [test_astobj2.c:astobj2_test_1_helper:488]: Hash container created: buckets: 161, items: 1000 1223s [test_astobj2.c:astobj2_test_1_helper:434]: Test 4, Hash containers (sorted). 1223s [test_astobj2.c:astobj2_test_1_helper:488]: Hash container created: buckets: 30, items: 1000 1223s [test_astobj2.c:astobj2_test_1_helper:434]: Test 4, RBTree containers (sorted). 1223s [test_astobj2.c:astobj2_test_1_helper:488]: RBTree container created: buckets: 1, items: 1000 1223s END /main/astobj2/ - astobj2_test1 Time: 7ms Result: PASS 1223s START /main/astobj2/ - thrash 1223s [test_astobj2_thrash.c:hash_test:266]: Executing hash concurrency test... 1223s END /main/astobj2/ - thrash Time: 33ms Result: PASS 1223s START /main/astobj2/ - astobj2_weak_container 1223s END /main/astobj2/ - astobj2_weak_container Time: <1ms Result: PASS 1223s START /main/astobj2/ - astobj2_weak1 1223s END /main/astobj2/ - astobj2_weak1 Time: <1ms Result: PASS 1223s START /main/astobj2/perf/ - astobj2_test_perf 1224s [test_astobj2.c:testloop:2001]: 20.00K traversals, List 1224s [test_astobj2.c:testloop:2001]: 40.00K traversals, List 1225s [test_astobj2.c:testloop:2001]: 60.00K traversals, List 1226s [test_astobj2.c:testloop:2001]: 80.00K traversals, List 1226s [test_astobj2.c:testloop:2006]: 100.00K traversals, List : 3112 ms 1227s [test_astobj2.c:testloop:2001]: 20.00K traversals, Hash 1227s [test_astobj2.c:testloop:2001]: 40.00K traversals, Hash 1227s [test_astobj2.c:testloop:2001]: 60.00K traversals, Hash 1228s [test_astobj2.c:testloop:2001]: 80.00K traversals, Hash 1228s [test_astobj2.c:testloop:2006]: 100.00K traversals, Hash : 1913 ms 1229s [test_astobj2.c:testloop:2001]: 20.00K traversals, RBTree 1229s [test_astobj2.c:testloop:2001]: 40.00K traversals, RBTree 1230s [test_astobj2.c:testloop:2001]: 60.00K traversals, RBTree 1230s [test_astobj2.c:testloop:2001]: 80.00K traversals, RBTree 1231s [test_astobj2.c:testloop:2006]: 100.00K traversals, RBTree : 2335 ms 1231s END /main/astobj2/perf/ - astobj2_test_perf Time: 7362ms Result: PASS 1231s START /main/bridging/ - test_bridging_deferred_queue 1232s END /main/bridging/ - test_bridging_deferred_queue Time: 1007ms Result: PASS 1232s START /main/bucket/ - bucket_file_json 1232s [test_bucket.c:bucket_file_json:956]: Failed to allocate bucket 1232s END /main/bucket/ - bucket_file_json Time: <1ms Result: FAIL 1232s START /main/bucket/ - bucket_file_metadata_get 1232s [test_bucket.c:bucket_file_metadata_get:914]: Failed to allocate file 1232s END /main/bucket/ - bucket_file_metadata_get Time: <1ms Result: FAIL 1232s START /main/bucket/ - bucket_file_metadata_unset 1232s [test_bucket.c:bucket_file_metadata_unset:874]: Failed to allocate file 1232s END /main/bucket/ - bucket_file_metadata_unset Time: <1ms Result: FAIL 1232s START /main/bucket/ - bucket_file_metadata_set 1232s [test_bucket.c:bucket_file_metadata_set:808]: Failed to allocate file 1232s END /main/bucket/ - bucket_file_metadata_set Time: <1ms Result: FAIL 1232s START /main/bucket/ - bucket_file_is_stale 1232s [test_bucket.c:bucket_file_is_stale:775]: Failed to allocate file 1232s END /main/bucket/ - bucket_file_is_stale Time: <1ms Result: FAIL 1232s START /main/bucket/ - bucket_file_delete 1232s [test_bucket.c:bucket_file_delete:732]: Failed to allocate file 1232s END /main/bucket/ - bucket_file_delete Time: <1ms Result: FAIL 1232s START /main/bucket/ - bucket_file_update 1232s [test_bucket.c:bucket_file_update:689]: Failed to allocate file 1232s END /main/bucket/ - bucket_file_update Time: <1ms Result: FAIL 1232s START /main/bucket/ - bucket_file_retrieve 1232s [test_bucket.c:bucket_file_retrieve:665]: Failed to retrieve known valid file 1232s END /main/bucket/ - bucket_file_retrieve Time: <1ms Result: FAIL 1232s START /main/bucket/ - bucket_file_copy 1232s [test_bucket.c:bucket_file_copy:594]: Failed to allocate file 1232s END /main/bucket/ - bucket_file_copy Time: <1ms Result: FAIL 1232s START /main/bucket/ - bucket_file_clone 1232s [test_bucket.c:bucket_file_clone:545]: Failed to allocate file 1232s END /main/bucket/ - bucket_file_clone Time: <1ms Result: FAIL 1232s START /main/bucket/ - bucket_file_create 1232s [test_bucket.c:bucket_file_create:501]: Failed to allocate file 1232s END /main/bucket/ - bucket_file_create Time: <1ms Result: FAIL 1232s START /main/bucket/ - bucket_file_alloc 1232s [test_bucket.c:bucket_file_alloc:460]: Failed to allocate file 1232s END /main/bucket/ - bucket_file_alloc Time: <1ms Result: FAIL 1232s START /main/bucket/ - bucket_json 1232s END /main/bucket/ - bucket_json Time: <1ms Result: PASS 1232s START /main/bucket/ - bucket_is_stale 1232s END /main/bucket/ - bucket_is_stale Time: <1ms Result: PASS 1232s START /main/bucket/ - bucket_retrieve 1232s END /main/bucket/ - bucket_retrieve Time: <1ms Result: PASS 1232s START /main/bucket/ - bucket_delete 1232s END /main/bucket/ - bucket_delete Time: <1ms Result: PASS 1232s START /main/bucket/ - bucket_clone 1232s END /main/bucket/ - bucket_clone Time: <1ms Result: PASS 1232s START /main/bucket/ - bucket_create 1232s END /main/bucket/ - bucket_create Time: <1ms Result: PASS 1232s START /main/bucket/ - bucket_alloc 1232s END /main/bucket/ - bucket_alloc Time: <1ms Result: PASS 1232s START /main/bucket/ - bucket_scheme_register_unregister 1232s END /main/bucket/ - bucket_scheme_register_unregister Time: <1ms Result: PASS 1232s START /main/callerid/ - parse_off_nominal 1232s END /main/callerid/ - parse_off_nominal Time: <1ms Result: PASS 1232s START /main/callerid/ - parse_nominal 1232s END /main/callerid/ - parse_nominal Time: <1ms Result: PASS 1232s START /main/cdr/ - test_cdr_fork_cdr 1234s Verifying expected record CDRTestChannel/Alice, 1234s Finished expected record CDRTestChannel/Alice, 1234s Verifying expected record CDRTestChannel/Alice, 1234s Finished expected record CDRTestChannel/Alice, 1234s Verifying expected record CDRTestChannel/Alice, 1234s Finished expected record CDRTestChannel/Alice, 1234s END /main/cdr/ - test_cdr_fork_cdr Time: 2000ms Result: PASS 1234s START /main/cdr/ - test_cdr_no_reset_cdr 1235s Verifying expected record CDRTestChannel/Alice, 1235s Finished expected record CDRTestChannel/Alice, 1235s END /main/cdr/ - test_cdr_no_reset_cdr Time: 1000ms Result: PASS 1235s START /main/cdr/ - test_cdr_fields 1237s Verifying expected record CDRTestChannel/Alice, 1237s Finished expected record CDRTestChannel/Alice, 1237s Verifying expected record CDRTestChannel/Alice, 1237s Finished expected record CDRTestChannel/Alice, 1237s Verifying expected record CDRTestChannel/Alice, 1237s Finished expected record CDRTestChannel/Alice, 1237s END /main/cdr/ - test_cdr_fields Time: 2000ms Result: PASS 1237s START /main/cdr/ - test_cdr_park 1240s Verifying expected record CDRTestChannel/Alice, 1240s Finished expected record CDRTestChannel/Alice, 1240s Verifying expected record CDRTestChannel/Bob, 1240s Finished expected record CDRTestChannel/Bob, 1240s END /main/cdr/ - test_cdr_park Time: 3001ms Result: PASS 1240s START /main/cdr/ - test_cdr_dial_answer_multiparty 1245s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 1245s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 1245s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Charlie 1245s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Charlie 1245s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/David 1245s Finished expected record CDRTestChannel/Alice, CDRTestChannel/David 1245s Verifying expected record CDRTestChannel/Bob, CDRTestChannel/David 1245s Finished expected record CDRTestChannel/Bob, CDRTestChannel/David 1245s Verifying expected record CDRTestChannel/Charlie, CDRTestChannel/David 1245s Finished expected record CDRTestChannel/Charlie, CDRTestChannel/David 1245s Verifying expected record CDRTestChannel/Charlie, CDRTestChannel/Bob 1245s Finished expected record CDRTestChannel/Charlie, CDRTestChannel/Bob 1245s END /main/cdr/ - test_cdr_dial_answer_multiparty Time: 5003ms Result: PASS 1245s START /main/cdr/ - test_cdr_dial_answer_twoparty_bridge_b 1248s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 1248s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 1248s END /main/cdr/ - test_cdr_dial_answer_twoparty_bridge_b Time: 3001ms Result: PASS 1248s START /main/cdr/ - test_cdr_dial_answer_twoparty_bridge_a 1250s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 1250s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 1250s END /main/cdr/ - test_cdr_dial_answer_twoparty_bridge_a Time: 2002ms Result: PASS 1250s START /main/cdr/ - test_cdr_dial_answer_no_bridge 1250s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 1250s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 1250s Verifying expected record CDRTestChannel/Alice, 1250s Finished expected record CDRTestChannel/Alice, 1250s Verifying expected record CDRTestChannel/Bob, 1250s Finished expected record CDRTestChannel/Bob, 1250s END /main/cdr/ - test_cdr_dial_answer_no_bridge Time: <1ms Result: PASS 1250s START /main/cdr/ - test_cdr_dial_parallel_failed 1250s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 1250s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 1250s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Charlie 1250s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Charlie 1250s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/David 1250s Finished expected record CDRTestChannel/Alice, CDRTestChannel/David 1250s END /main/cdr/ - test_cdr_dial_parallel_failed Time: <1ms Result: PASS 1250s START /main/cdr/ - test_cdr_dial_caller_cancel 1250s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 1250s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 1250s END /main/cdr/ - test_cdr_dial_caller_cancel Time: <1ms Result: PASS 1250s START /main/cdr/ - test_cdr_dial_unavailable 1250s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 1250s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 1250s END /main/cdr/ - test_cdr_dial_unavailable Time: <1ms Result: PASS 1250s START /main/cdr/ - test_cdr_dial_busy 1250s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 1250s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 1250s END /main/cdr/ - test_cdr_dial_busy Time: <1ms Result: PASS 1250s START /main/cdr/ - test_cdr_dial_congestion 1250s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 1250s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 1250s END /main/cdr/ - test_cdr_dial_congestion Time: <1ms Result: PASS 1250s START /main/cdr/ - test_cdr_dial_unanswered 1250s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 1250s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 1250s END /main/cdr/ - test_cdr_dial_unanswered Time: <1ms Result: PASS 1250s START /main/cdr/ - test_cdr_outbound_bridged_call 1253s Verifying expected record CDRTestChannel/Bob, 1253s Finished expected record CDRTestChannel/Bob, 1253s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 1253s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 1253s END /main/cdr/ - test_cdr_outbound_bridged_call Time: 3004ms Result: PASS 1253s START /main/cdr/ - test_cdr_single_multiparty_bridge 1257s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 1257s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 1257s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Charlie 1257s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Charlie 1257s Verifying expected record CDRTestChannel/Bob, CDRTestChannel/Charlie 1257s Finished expected record CDRTestChannel/Bob, CDRTestChannel/Charlie 1257s Verifying expected record CDRTestChannel/Charlie, 1257s Finished expected record CDRTestChannel/Charlie, 1257s END /main/cdr/ - test_cdr_single_multiparty_bridge Time: 4002ms Result: PASS 1257s START /main/cdr/ - test_cdr_single_twoparty_bridge_b 1260s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 1260s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 1260s Verifying expected record CDRTestChannel/Bob, 1260s Finished expected record CDRTestChannel/Bob, 1260s END /main/cdr/ - test_cdr_single_twoparty_bridge_b Time: 3001ms Result: PASS 1260s START /main/cdr/ - test_cdr_single_twoparty_bridge_a 1262s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 1262s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 1262s Verifying expected record CDRTestChannel/Bob, 1262s Finished expected record CDRTestChannel/Bob, 1262s END /main/cdr/ - test_cdr_single_twoparty_bridge_a Time: 2001ms Result: PASS 1262s START /main/cdr/ - test_cdr_single_bridge_continue 1264s Verifying expected record CDRTestChannel/Alice, 1264s Finished expected record CDRTestChannel/Alice, 1264s Verifying expected record CDRTestChannel/Alice, 1264s Finished expected record CDRTestChannel/Alice, 1264s END /main/cdr/ - test_cdr_single_bridge_continue Time: 2001ms Result: PASS 1264s START /main/cdr/ - test_cdr_single_bridge 1266s Verifying expected record CDRTestChannel/Alice, 1266s Finished expected record CDRTestChannel/Alice, 1266s END /main/cdr/ - test_cdr_single_bridge Time: 2001ms Result: PASS 1266s START /main/cdr/ - test_cdr_single_party 1266s Verifying expected record CDRTestChannel/Alice, 1266s Finished expected record CDRTestChannel/Alice, 1266s END /main/cdr/ - test_cdr_single_party Time: <1ms Result: PASS 1266s START /main/cdr/ - test_cdr_unanswered_outbound_call 1266s Verifying expected record CDRTestChannel/Alice, 1266s Finished expected record CDRTestChannel/Alice, 1266s END /main/cdr/ - test_cdr_unanswered_outbound_call Time: <1ms Result: PASS 1266s START /main/cdr/ - test_cdr_unanswered_inbound_call 1266s Verifying expected record CDRTestChannel/Alice, 1266s Finished expected record CDRTestChannel/Alice, 1266s END /main/cdr/ - test_cdr_unanswered_inbound_call Time: <1ms Result: PASS 1266s START /main/cdr/ - test_cdr_channel_creation 1266s Verifying expected record CDRTestChannel/Alice, 1266s Finished expected record CDRTestChannel/Alice, 1266s END /main/cdr/ - test_cdr_channel_creation Time: <1ms Result: PASS 1266s START /main/channel/ - add_fd 1266s END /main/channel/ - add_fd Time: <1ms Result: PASS 1266s START /main/channel/ - set_fd_grow 1266s END /main/channel/ - set_fd_grow Time: <1ms Result: PASS 1266s START /main/config/ - variable_list_from_quoted_string 1266s END /main/config/ - variable_list_from_quoted_string Time: <1ms Result: PASS 1266s START /main/config/ - variable_list_join_replace 1266s END /main/config/ - variable_list_join_replace Time: <1ms Result: PASS 1266s START /main/config/ - variable_lists_match 1266s END /main/config/ - variable_lists_match Time: <1ms Result: PASS 1266s START /main/config/ - config_dialplan_function 1266s END /main/config/ - config_dialplan_function Time: <1ms Result: PASS 1266s START /main/config/ - config_hook 1266s END /main/config/ - config_hook Time: <1ms Result: PASS 1266s START /main/config/ - copy_config 1266s END /main/config/ - copy_config Time: <1ms Result: PASS 1266s START /main/config/ - config_template_ops 1266s END /main/config/ - config_template_ops Time: <1ms Result: PASS 1266s START /main/config/ - config_filtered_ops 1266s END /main/config/ - config_filtered_ops Time: <1ms Result: PASS 1266s START /main/config/ - config_basic_ops 1266s END /main/config/ - config_basic_ops Time: <1ms Result: PASS 1266s START /main/config/ - config_save 1266s END /main/config/ - config_save Time: <1ms Result: PASS 1266s START /main/conversions/ - str_to_umax 1266s END /main/conversions/ - str_to_umax Time: <1ms Result: PASS 1266s START /main/conversions/ - str_to_imax 1266s END /main/conversions/ - str_to_imax Time: <1ms Result: PASS 1266s START /main/conversions/ - str_to_ulong 1266s END /main/conversions/ - str_to_ulong Time: <1ms Result: PASS 1266s START /main/conversions/ - str_to_long 1266s END /main/conversions/ - str_to_long Time: <1ms Result: PASS 1266s START /main/conversions/ - str_to_uint 1266s END /main/conversions/ - str_to_uint Time: <1ms Result: PASS 1266s START /main/conversions/ - str_to_int 1266s END /main/conversions/ - str_to_int Time: <1ms Result: PASS 1266s START /main/core_codec/ - codec_get_unknown 1266s END /main/core_codec/ - codec_get_unknown Time: <1ms Result: PASS 1266s START /main/core_codec/ - codec_get_unknown 1266s END /main/core_codec/ - codec_get_unknown Time: <1ms Result: PASS 1266s START /main/core_codec/ - codec_get_unregistered 1266s END /main/core_codec/ - codec_get_unregistered Time: <1ms Result: PASS 1266s START /main/core_codec/ - codec_get 1266s END /main/core_codec/ - codec_get Time: <1ms Result: PASS 1266s START /main/core_codec/ - codec_register_audio_no_sample_rate 1266s END /main/core_codec/ - codec_register_audio_no_sample_rate Time: <1ms Result: PASS 1266s START /main/core_codec/ - codec_register_unknown 1266s END /main/core_codec/ - codec_register_unknown Time: <1ms Result: PASS 1266s START /main/core_codec/ - codec_register_twice 1266s END /main/core_codec/ - codec_register_twice Time: <1ms Result: PASS 1266s START /main/core_codec/ - codec_register 1266s END /main/core_codec/ - codec_register Time: <1ms Result: PASS 1266s START /main/core_format/ - format_parse_and_generate_sdp_fmtp 1266s END /main/core_format/ - format_parse_and_generate_sdp_fmtp Time: <1ms Result: PASS 1266s START /main/core_format/ - format_parse_sdp_fmtp_without_interface 1266s END /main/core_format/ - format_parse_sdp_fmtp_without_interface Time: <1ms Result: PASS 1266s START /main/core_format/ - format_attribute_get_without_interface 1266s END /main/core_format/ - format_attribute_get_without_interface Time: <1ms Result: PASS 1266s START /main/core_format/ - format_attribute_set_without_interface 1266s END /main/core_format/ - format_attribute_set_without_interface Time: <1ms Result: PASS 1266s START /main/core_format/ - format_copy 1266s END /main/core_format/ - format_copy Time: <1ms Result: PASS 1266s START /main/core_format/ - format_joint_different_codec 1266s END /main/core_format/ - format_joint_different_codec Time: <1ms Result: PASS 1266s START /main/core_format/ - format_attr_joint_same_codec 1266s END /main/core_format/ - format_attr_joint_same_codec Time: <1ms Result: PASS 1266s START /main/core_format/ - format_joint_same_codec 1266s END /main/core_format/ - format_joint_same_codec Time: <1ms Result: PASS 1266s START /main/core_format/ - format_cmp_different_codec 1266s END /main/core_format/ - format_cmp_different_codec Time: <1ms Result: PASS 1266s START /main/core_format/ - format_attr_cmp_same_codec 1266s END /main/core_format/ - format_attr_cmp_same_codec Time: <1ms Result: PASS 1266s START /main/core_format/ - format_cmp_same_codec 1266s END /main/core_format/ - format_cmp_same_codec Time: <1ms Result: PASS 1266s START /main/core_format/ - format_clone 1266s END /main/core_format/ - format_clone Time: <1ms Result: PASS 1266s START /main/core_format/ - format_retrieve_attr 1266s END /main/core_format/ - format_retrieve_attr Time: <1ms Result: PASS 1266s START /main/core_format/ - format_create_attr 1266s END /main/core_format/ - format_create_attr Time: <1ms Result: PASS 1266s START /main/core_format/ - format_create 1266s END /main/core_format/ - format_create Time: <1ms Result: PASS 1266s START /main/data_buffer/ - buffer_nominal 1266s END /main/data_buffer/ - buffer_nominal Time: <1ms Result: PASS 1266s START /main/data_buffer/ - buffer_resize 1266s END /main/data_buffer/ - buffer_resize Time: <1ms Result: PASS 1266s START /main/data_buffer/ - buffer_put 1266s END /main/data_buffer/ - buffer_put Time: <1ms Result: PASS 1266s START /main/data_buffer/ - buffer_create 1266s END /main/data_buffer/ - buffer_create Time: <1ms Result: PASS 1266s START /main/devicestate/ - devstate_channels 1266s END /main/devicestate/ - devstate_channels Time: <1ms Result: PASS 1266s START /main/devicestate/ - devstate_conversions 1266s END /main/devicestate/ - devstate_conversions Time: <1ms Result: PASS 1266s START /main/devicestate/ - devstate_changed 1266s [test_devicestate.c:wait_for_device_state_updates:308]: Received 8 of 8 updates 1266s [test_devicestate.c:devstate_changed:716]: Testing update 0: actual is 1; expected is 1 1266s [test_devicestate.c:devstate_changed:716]: Testing update 1: actual is 2; expected is 2 1266s [test_devicestate.c:devstate_changed:716]: Testing update 2: actual is 3; expected is 3 1266s [test_devicestate.c:devstate_changed:716]: Testing update 3: actual is 4; expected is 4 1266s [test_devicestate.c:devstate_changed:716]: Testing update 4: actual is 5; expected is 5 1266s [test_devicestate.c:devstate_changed:716]: Testing update 5: actual is 6; expected is 6 1266s [test_devicestate.c:devstate_changed:716]: Testing update 6: actual is 7; expected is 7 1266s [test_devicestate.c:devstate_changed:716]: Testing update 7: actual is 8; expected is 8 1266s [test_devicestate.c:wait_for_device_state_updates:308]: Received 1 of 1 updates 1266s [test_devicestate.c:wait_for_device_state_updates:308]: Received 8 of 8 updates 1266s [test_devicestate.c:devstate_changed:754]: Testing update 0: actual is 1; expected is 1 1266s [test_devicestate.c:devstate_changed:754]: Testing update 1: actual is 2; expected is 2 1266s [test_devicestate.c:devstate_changed:754]: Testing update 2: actual is 3; expected is 3 1266s [test_devicestate.c:devstate_changed:754]: Testing update 3: actual is 4; expected is 4 1266s [test_devicestate.c:devstate_changed:754]: Testing update 4: actual is 5; expected is 5 1266s [test_devicestate.c:devstate_changed:754]: Testing update 5: actual is 6; expected is 6 1266s [test_devicestate.c:devstate_changed:754]: Testing update 6: actual is 7; expected is 7 1266s [test_devicestate.c:devstate_changed:754]: Testing update 7: actual is 8; expected is 8 1266s END /main/devicestate/ - devstate_changed Time: 1ms Result: PASS 1266s START /main/devicestate/ - devstate_prov_del 1266s END /main/devicestate/ - devstate_prov_del Time: <1ms Result: PASS 1266s START /main/devicestate/ - devstate_prov_add 1266s END /main/devicestate/ - devstate_prov_add Time: <1ms Result: PASS 1266s START /main/devicestate/ - device2extenstate_test 1266s END /main/devicestate/ - device2extenstate_test Time: <1ms Result: PASS 1266s START /main/devicestate/ - device_state_aggregation_test 1266s END /main/devicestate/ - device_state_aggregation_test Time: <1ms Result: PASS 1266s START /main/dns/ - resolver_resolve_async_cancel 1266s END /main/dns/ - resolver_resolve_async_cancel Time: <1ms Result: PASS 1266s START /main/dns/ - resolver_resolve_async_off_nominal 1266s END /main/dns/ - resolver_resolve_async_off_nominal Time: <1ms Result: PASS 1266s START /main/dns/ - resolver_resolve_async 1271s END /main/dns/ - resolver_resolve_async Time: 5000ms Result: PASS 1271s START /main/dns/ - resolver_resolve_sync_off_nominal 1271s END /main/dns/ - resolver_resolve_sync_off_nominal Time: <1ms Result: PASS 1271s START /main/dns/ - resolver_resolve_sync 1276s END /main/dns/ - resolver_resolve_sync Time: 5000ms Result: PASS 1276s START /main/dns/ - resolver_add_record_off_nominal 1276s END /main/dns/ - resolver_add_record_off_nominal Time: <1ms Result: PASS 1276s START /main/dns/ - resolver_add_record 1276s END /main/dns/ - resolver_add_record Time: <1ms Result: PASS 1276s START /main/dns/ - resolver_set_result_off_nominal 1276s END /main/dns/ - resolver_set_result_off_nominal Time: <1ms Result: PASS 1276s START /main/dns/ - resolver_set_result 1276s END /main/dns/ - resolver_set_result Time: <1ms Result: PASS 1276s START /main/dns/ - resolver_data 1276s END /main/dns/ - resolver_data Time: <1ms Result: PASS 1276s START /main/dns/ - resolver_unregister_off_nominal 1276s END /main/dns/ - resolver_unregister_off_nominal Time: <1ms Result: PASS 1276s START /main/dns/ - resolver_register_off_nominal 1276s END /main/dns/ - resolver_register_off_nominal Time: <1ms Result: PASS 1276s START /main/dns/ - resolver_register_unregister 1276s END /main/dns/ - resolver_register_unregister Time: <1ms Result: PASS 1276s START /main/dns/naptr/ - naptr_resolve_off_nominal_interactions 1276s END /main/dns/naptr/ - naptr_resolve_off_nominal_interactions Time: <1ms Result: PASS 1276s START /main/dns/naptr/ - naptr_resolve_off_nominal_regexp 1276s END /main/dns/naptr/ - naptr_resolve_off_nominal_regexp Time: <1ms Result: PASS 1276s START /main/dns/naptr/ - naptr_resolve_off_nominal_services 1276s END /main/dns/naptr/ - naptr_resolve_off_nominal_services Time: <1ms Result: PASS 1276s START /main/dns/naptr/ - naptr_resolve_off_nominal_flags 1276s END /main/dns/naptr/ - naptr_resolve_off_nominal_flags Time: <1ms Result: PASS 1276s START /main/dns/naptr/ - naptr_resolve_off_nominal_length 1276s END /main/dns/naptr/ - naptr_resolve_off_nominal_length Time: <1ms Result: PASS 1276s START /main/dns/naptr/ - naptr_resolve 1276s END /main/dns/naptr/ - naptr_resolve Time: <1ms Result: PASS 1276s START /main/dns/query_set/ - query_set_off_nominal_cancel 1276s END /main/dns/query_set/ - query_set_off_nominal_cancel Time: <1ms Result: PASS 1276s START /main/dns/query_set/ - query_set_nominal_cancel 1276s END /main/dns/query_set/ - query_set_nominal_cancel Time: <1ms Result: PASS 1276s START /main/dns/query_set/ - query_set_empty 1276s END /main/dns/query_set/ - query_set_empty Time: <1ms Result: PASS 1276s START /main/dns/query_set/ - query_set 1276s END /main/dns/query_set/ - query_set Time: <1ms Result: PASS 1276s START /main/dns/recurring/ - recurring_query_cancel_during 1276s [test_dns_recurring.c:wait_for_resolution:252]: Query completed in expected time frame 1283s [test_dns_recurring.c:wait_for_resolution:252]: Query completed in expected time frame 1293s END /main/dns/recurring/ - recurring_query_cancel_during Time: 16999ms Result: PASS 1293s START /main/dns/recurring/ - recurring_query_cancel_between 1293s [test_dns_recurring.c:wait_for_resolution:252]: Query completed in expected time frame 1303s END /main/dns/recurring/ - recurring_query_cancel_between Time: 10000ms Result: PASS 1303s START /main/dns/recurring/ - recurring_query_off_nominal 1303s END /main/dns/recurring/ - recurring_query_off_nominal Time: <1ms Result: PASS 1303s START /main/dns/recurring/ - recurring_query 1303s [test_dns_recurring.c:wait_for_resolution:252]: Query completed in expected time frame 1310s [test_dns_recurring.c:wait_for_resolution:252]: Query completed in expected time frame 1322s [test_dns_recurring.c:wait_for_resolution:252]: Query completed in expected time frame 1322s END /main/dns/recurring/ - recurring_query Time: 18998ms Result: PASS 1322s START /main/dns/srv/ - srv_resolve_record_missing_host 1322s END /main/dns/srv/ - srv_resolve_record_missing_host Time: <1ms Result: PASS 1322s START /main/dns/srv/ - srv_resolve_record_missing_port_host 1322s END /main/dns/srv/ - srv_resolve_record_missing_port_host Time: <1ms Result: PASS 1322s START /main/dns/srv/ - srv_resolve_record_missing_weight_port_host 1322s END /main/dns/srv/ - srv_resolve_record_missing_weight_port_host Time: <1ms Result: PASS 1322s START /main/dns/srv/ - srv_resolve_different_priorities_different_weights 1322s END /main/dns/srv/ - srv_resolve_different_priorities_different_weights Time: 5ms Result: PASS 1322s START /main/dns/srv/ - srv_resolve_same_priority_different_weights 1322s END /main/dns/srv/ - srv_resolve_same_priority_different_weights Time: 5ms Result: PASS 1322s START /main/dns/srv/ - srv_resolve_same_priority_zero_weight 1322s END /main/dns/srv/ - srv_resolve_same_priority_zero_weight Time: <1ms Result: PASS 1322s START /main/dns/srv/ - srv_resolve_sort_priority 1322s END /main/dns/srv/ - srv_resolve_sort_priority Time: <1ms Result: PASS 1322s START /main/dns/srv/ - srv_resolve_single_record 1322s END /main/dns/srv/ - srv_resolve_single_record Time: <1ms Result: PASS 1322s START /main/dsp/ - dtmf 1322s END /main/dsp/ - dtmf Time: 2ms Result: PASS 1322s START /main/dsp/ - fax 1322s END /main/dsp/ - fax Time: 347ms Result: PASS 1322s START /main/event/ - ast_event_new_test 1322s [test_event.c:event_new_test:125]: First, test dynamic event creation... 1322s [test_event.c:check_event:88]: Event looks good. 1322s [test_event.c:check_event:88]: Event looks good. 1322s END /main/event/ - ast_event_new_test Time: <1ms Result: PASS 1322s START /main/file/ - read_dir_test 1322s END /main/file/ - read_dir_test Time: <1ms Result: PASS 1322s START /main/file/ - ast_format_str_reduce_test_1 1322s END /main/file/ - ast_format_str_reduce_test_1 Time: <1ms Result: PASS 1322s START /main/format_cache/ - format_cache_get_nonxistent 1322s END /main/format_cache/ - format_cache_get_nonxistent Time: <1ms Result: PASS 1322s START /main/format_cache/ - format_cache_get 1322s END /main/format_cache/ - format_cache_get Time: <1ms Result: PASS 1322s START /main/format_cache/ - format_cache_set_null 1322s END /main/format_cache/ - format_cache_set_null Time: <1ms Result: PASS 1322s START /main/format_cache/ - format_cache_set_duplicate 1322s END /main/format_cache/ - format_cache_set_duplicate Time: <1ms Result: PASS 1322s START /main/format_cache/ - format_cache_set 1322s END /main/format_cache/ - format_cache_set Time: <1ms Result: PASS 1322s START /main/format_cap/ - format_cap_replace_from_cap 1322s END /main/format_cap/ - format_cap_replace_from_cap Time: <1ms Result: PASS 1322s START /main/format_cap/ - format_cap_best_by_type 1322s END /main/format_cap/ - format_cap_best_by_type Time: <1ms Result: PASS 1322s START /main/format_cap/ - format_cap_iscompatible 1322s END /main/format_cap/ - format_cap_iscompatible Time: <1ms Result: PASS 1322s START /main/format_cap/ - format_cap_get_compatible 1322s END /main/format_cap/ - format_cap_get_compatible Time: <1ms Result: PASS 1322s START /main/format_cap/ - format_cap_iscompatible_format 1322s END /main/format_cap/ - format_cap_iscompatible_format Time: <1ms Result: PASS 1322s START /main/format_cap/ - format_cap_get_compatible_format 1322s END /main/format_cap/ - format_cap_get_compatible_format Time: <1ms Result: PASS 1322s START /main/format_cap/ - format_cap_get_names 1322s END /main/format_cap/ - format_cap_get_names Time: <1ms Result: PASS 1322s START /main/format_cap/ - format_cap_remove_all 1322s END /main/format_cap/ - format_cap_remove_all Time: <1ms Result: PASS 1322s START /main/format_cap/ - format_cap_remove_bytype 1322s END /main/format_cap/ - format_cap_remove_bytype Time: <1ms Result: PASS 1322s START /main/format_cap/ - format_cap_remove_multiple 1322s END /main/format_cap/ - format_cap_remove_multiple Time: <1ms Result: PASS 1322s START /main/format_cap/ - format_cap_remove_single 1322s END /main/format_cap/ - format_cap_remove_single Time: <1ms Result: PASS 1322s START /main/format_cap/ - format_cap_set_framing 1322s END /main/format_cap/ - format_cap_set_framing Time: <1ms Result: PASS 1322s START /main/format_cap/ - format_cap_append_from_cap_duplicate 1322s END /main/format_cap/ - format_cap_append_from_cap_duplicate Time: <1ms Result: PASS 1322s START /main/format_cap/ - format_cap_append_from_cap 1322s END /main/format_cap/ - format_cap_append_from_cap Time: <1ms Result: PASS 1322s START /main/format_cap/ - format_cap_append_duplicate 1322s END /main/format_cap/ - format_cap_append_duplicate Time: <1ms Result: PASS 1322s START /main/format_cap/ - format_cap_append_all_audio 1322s END /main/format_cap/ - format_cap_append_all_audio Time: <1ms Result: PASS 1322s START /main/format_cap/ - format_cap_append_all_unknown 1322s END /main/format_cap/ - format_cap_append_all_unknown Time: <1ms Result: PASS 1322s START /main/format_cap/ - format_cap_append_multiple 1322s END /main/format_cap/ - format_cap_append_multiple Time: <1ms Result: PASS 1322s START /main/format_cap/ - format_cap_append_single 1322s END /main/format_cap/ - format_cap_append_single Time: <1ms Result: PASS 1322s START /main/format_cap/ - format_cap_alloc 1322s END /main/format_cap/ - format_cap_alloc Time: <1ms Result: PASS 1322s START /main/hashtab/ - thrash 1322s [test_hashtab_thrash.c:hash_test:246]: Executing hash concurrency test... 1322s END /main/hashtab/ - thrash Time: 16ms Result: PASS 1322s START /main/heap/ - heap_test_3 1322s END /main/heap/ - heap_test_3 Time: 119ms Result: PASS 1322s START /main/heap/ - heap_test_2 1322s END /main/heap/ - heap_test_2 Time: 111ms Result: PASS 1322s START /main/heap/ - heap_test_1 1322s END /main/heap/ - heap_test_1 Time: <1ms Result: PASS 1322s START /main/jitterbuf/ - jitterbuffer_resynch_control 1322s END /main/jitterbuf/ - jitterbuffer_resynch_control Time: <1ms Result: PASS 1322s START /main/jitterbuf/ - jitterbuffer_resynch_voice 1322s END /main/jitterbuf/ - jitterbuffer_resynch_voice Time: <1ms Result: PASS 1322s START /main/jitterbuf/ - jitterbuffer_overflow_control 1322s END /main/jitterbuf/ - jitterbuffer_overflow_control Time: <1ms Result: PASS 1322s START /main/jitterbuf/ - jitterbuffer_overflow_voice 1322s END /main/jitterbuf/ - jitterbuffer_overflow_voice Time: <1ms Result: PASS 1322s START /main/jitterbuf/ - jitterbuffer_late_control 1322s END /main/jitterbuf/ - jitterbuffer_late_control Time: <1ms Result: PASS 1322s START /main/jitterbuf/ - jitterbuffer_late_voice 1322s END /main/jitterbuf/ - jitterbuffer_late_voice Time: <1ms Result: PASS 1322s START /main/jitterbuf/ - jitterbuffer_lost_control 1322s END /main/jitterbuf/ - jitterbuffer_lost_control Time: <1ms Result: PASS 1322s START /main/jitterbuf/ - jitterbuffer_lost_voice 1322s END /main/jitterbuf/ - jitterbuffer_lost_voice Time: <1ms Result: PASS 1322s START /main/jitterbuf/ - jitterbuffer_out_of_order_voice 1322s END /main/jitterbuf/ - jitterbuffer_out_of_order_voice Time: <1ms Result: PASS 1322s START /main/jitterbuf/ - jitterbuffer_out_of_order_voice 1322s END /main/jitterbuf/ - jitterbuffer_out_of_order_voice Time: <1ms Result: PASS 1322s START /main/jitterbuf/ - jitterbuffer_nominal_control_frames 1322s END /main/jitterbuf/ - jitterbuffer_nominal_control_frames Time: <1ms Result: PASS 1322s START /main/jitterbuf/ - jitterbuffer_nominal_voice_frames 1322s END /main/jitterbuf/ - jitterbuffer_nominal_voice_frames Time: <1ms Result: PASS 1322s START /main/json/ - cep 1322s END /main/json/ - cep Time: <1ms Result: PASS 1322s START /main/json/ - type_timeval 1322s END /main/json/ - type_timeval Time: <1ms Result: PASS 1322s START /main/json/ - name_number 1322s END /main/json/ - name_number Time: <1ms Result: PASS 1322s START /main/json/ - clever_circle 1322s END /main/json/ - clever_circle Time: <1ms Result: PASS 1322s START /main/json/ - circular_array 1322s END /main/json/ - circular_array Time: <1ms Result: PASS 1322s START /main/json/ - circular_object 1322s END /main/json/ - circular_object Time: <1ms Result: PASS 1322s START /main/json/ - copy_null 1322s END /main/json/ - copy_null Time: <1ms Result: PASS 1322s START /main/json/ - deep_copy 1322s END /main/json/ - deep_copy Time: <1ms Result: PASS 1322s START /main/json/ - copy 1322s END /main/json/ - copy Time: <1ms Result: PASS 1322s START /main/json/ - object_alloc 1322s END /main/json/ - object_alloc Time: <1ms Result: PASS 1322s START /main/json/ - pack_ownership 1322s END /main/json/ - pack_ownership Time: <1ms Result: PASS 1322s START /main/json/ - pack 1322s END /main/json/ - pack Time: <1ms Result: PASS 1322s START /main/json/ - parse_errors 1322s END /main/json/ - parse_errors Time: <1ms Result: PASS 1322s START /main/json/ - dump_load_null 1322s END /main/json/ - dump_load_null Time: <1ms Result: PASS 1322s START /main/json/ - dump_load_new_file 1322s END /main/json/ - dump_load_new_file Time: <1ms Result: PASS 1322s START /main/json/ - dump_load_file 1322s END /main/json/ - dump_load_file Time: <1ms Result: PASS 1322s START /main/json/ - load_buffer 1322s END /main/json/ - load_buffer Time: <1ms Result: PASS 1322s START /main/json/ - dump_str_fail 1322s END /main/json/ - dump_str_fail Time: <1ms Result: PASS 1322s START /main/json/ - dump_load_str 1322s END /main/json/ - dump_load_str Time: <1ms Result: PASS 1322s START /main/json/ - dump_load_string 1322s END /main/json/ - dump_load_string Time: <1ms Result: PASS 1322s START /main/json/ - object_create_vars 1322s END /main/json/ - object_create_vars Time: <1ms Result: PASS 1322s START /main/json/ - object_iter_null 1322s END /main/json/ - object_iter_null Time: <1ms Result: PASS 1322s START /main/json/ - object_iter 1322s END /main/json/ - object_iter Time: <1ms Result: PASS 1322s START /main/json/ - object_null 1322s END /main/json/ - object_null Time: <1ms Result: PASS 1322s START /main/json/ - object_merge_missing 1322s END /main/json/ - object_merge_missing Time: <1ms Result: PASS 1322s START /main/json/ - object_alloc 1322s END /main/json/ - object_alloc Time: <1ms Result: PASS 1322s START /main/json/ - object_alloc 1322s END /main/json/ - object_alloc Time: <1ms Result: PASS 1322s START /main/json/ - object_clear 1322s END /main/json/ - object_clear Time: <1ms Result: PASS 1322s START /main/json/ - object_del 1322s END /main/json/ - object_del Time: <1ms Result: PASS 1322s START /main/json/ - object_get 1322s END /main/json/ - object_get Time: <1ms Result: PASS 1322s START /main/json/ - object_set_overwriting 1322s END /main/json/ - object_set_overwriting Time: <1ms Result: PASS 1322s START /main/json/ - object_set 1322s END /main/json/ - object_set Time: <1ms Result: PASS 1322s START /main/json/ - object_alloc 1322s END /main/json/ - object_alloc Time: <1ms Result: PASS 1322s START /main/json/ - array_null 1322s END /main/json/ - array_null Time: <1ms Result: PASS 1322s START /main/json/ - array_extend 1322s END /main/json/ - array_extend Time: <1ms Result: PASS 1322s START /main/json/ - array_clear 1322s END /main/json/ - array_clear Time: <1ms Result: PASS 1322s START /main/json/ - array_remove 1322s END /main/json/ - array_remove Time: <1ms Result: PASS 1322s START /main/json/ - array_set 1322s END /main/json/ - array_set Time: <1ms Result: PASS 1322s START /main/json/ - array_insert 1322s END /main/json/ - array_insert Time: <1ms Result: PASS 1322s START /main/json/ - array_append 1322s END /main/json/ - array_append Time: <1ms Result: PASS 1322s START /main/json/ - array_create 1322s END /main/json/ - array_create Time: <1ms Result: PASS 1322s START /main/json/ - non_int 1322s END /main/json/ - non_int Time: <1ms Result: PASS 1322s START /main/json/ - type_int 1322s END /main/json/ - type_int Time: <1ms Result: PASS 1322s START /main/json/ - stringf 1322s END /main/json/ - stringf Time: <1ms Result: PASS 1322s START /main/json/ - string_null 1322s END /main/json/ - string_null Time: <1ms Result: PASS 1322s START /main/json/ - type_string 1322s END /main/json/ - type_string Time: <1ms Result: PASS 1322s START /main/json/ - null_val 1322s END /main/json/ - null_val Time: <1ms Result: PASS 1322s START /main/json/ - type_null 1322s END /main/json/ - type_null Time: <1ms Result: PASS 1322s START /main/json/ - type_bool1 1322s END /main/json/ - type_bool1 Time: <1ms Result: PASS 1322s START /main/json/ - type_bool0 1322s END /main/json/ - type_bool0 Time: <1ms Result: PASS 1322s START /main/json/ - type_true 1322s END /main/json/ - type_true Time: <1ms Result: PASS 1322s START /main/json/ - type_false 1322s END /main/json/ - type_false Time: <1ms Result: PASS 1322s START /main/linkedlists/ - double_ll_tests 1322s END /main/linkedlists/ - double_ll_tests Time: <1ms Result: PASS 1322s START /main/linkedlists/ - ll_tests 1322s END /main/linkedlists/ - ll_tests Time: <1ms Result: PASS 1322s START /main/lock/ - named_lock_test 1322s [test_named_lock.c:named_lock_test:80]: This test should take about 3 seconds 1325s END /main/lock/ - named_lock_test Time: 3000ms Result: PASS 1325s START /main/lock/ - cleanup_order_test 1325s [test_scoped_lock.c:test_ref:149]: Ref is occurring 1325s [test_scoped_lock.c:test_lock:117]: Lock is occurring 1325s [test_scoped_lock.c:test_unlock:133]: Unlock is occurring 1325s [test_scoped_lock.c:test_unref:166]: Unref is occurring 1325s [test_scoped_lock.c:test_ref:149]: Ref is occurring 1325s [test_scoped_lock.c:test_lock:117]: Lock is occurring 1325s [test_scoped_lock.c:test_unlock:133]: Unlock is occurring 1325s [test_scoped_lock.c:test_unref:166]: Unref is occurring 1325s END /main/lock/ - cleanup_order_test Time: <1ms Result: PASS 1325s START /main/lock/ - lock_test 1325s END /main/lock/ - lock_test Time: <1ms Result: PASS 1325s START /main/logging/ - scope_test 1325s END /main/logging/ - scope_test Time: <1ms Result: PASS 1325s START /main/media_cache/ - create_update_off_nominal 1325s END /main/media_cache/ - create_update_off_nominal Time: <1ms Result: PASS 1325s START /main/media_cache/ - create_update_metadata 1325s [test_media_cache.c:create_update_metadata:364]: Got /tmp/test-media-cache-9hgSmf for second file path 1325s END /main/media_cache/ - create_update_metadata Time: <1ms Result: PASS 1325s START /main/media_cache/ - create_update_nominal 1325s [test_media_cache.c:create_update_nominal:235]: Creating resource with /tmp/test-media-cache-vUtVPA 1325s [test_media_cache.c:create_update_nominal:240]: Got /tmp/test-media-cache-vUtVPA for first file path 1325s [test_media_cache.c:create_update_nominal:244]: Creating resource with /tmp/test-media-cache-JTeWZ2 1325s [test_media_cache.c:create_update_nominal:249]: Got /tmp/test-media-cache-JTeWZ2 for second file path 1325s END /main/media_cache/ - create_update_nominal Time: <1ms Result: PASS 1325s START /main/media_cache/ - exists_off_nominal 1325s END /main/media_cache/ - exists_off_nominal Time: <1ms Result: PASS 1325s START /main/media_cache/ - exists_nominal 1325s END /main/media_cache/ - exists_nominal Time: <1ms Result: PASS 1325s START /main/netsock2/ - split_hostport 1325s END /main/netsock2/ - split_hostport Time: <1ms Result: PASS 1325s START /main/netsock2/ - parsing 1325s END /main/netsock2/ - parsing Time: <1ms Result: PASS 1325s START /main/optional_api/ - test_provide_last 1325s END /main/optional_api/ - test_provide_last Time: <1ms Result: PASS 1325s START /main/optional_api/ - test_provide_first 1325s END /main/optional_api/ - test_provide_first Time: <1ms Result: PASS 1325s START /main/pbx/ - test_MATH_function 1325s [func_math.c:test_MATH_function:682]: Testing MATH() substitution ... 1325s END /main/pbx/ - test_MATH_function Time: <1ms Result: PASS 1325s START /main/pbx/ - pattern_match_test 1325s [test_pbx.c:test_exten:183]: Successfully matched 200 to exten _2. in context test_pattern with the old pattern match engine 1325s [test_pbx.c:test_exten:183]: Successfully matched 2000 to exten 2000 in context test_pattern with the old pattern match engine 1325s [test_pbx.c:test_exten:183]: Successfully matched 2000 to exten 2000 in context test_pattern with the old pattern match engine 1325s [test_pbx.c:test_exten:183]: Successfully matched 2000 to exten 2000 in context test_pattern_include with the old pattern match engine 1325s [test_pbx.c:test_exten:183]: Successfully matched 200 to exten _2. in context test_pattern with the new pattern match engine 1325s [test_pbx.c:test_exten:183]: Successfully matched 2000 to exten 2000 in context test_pattern with the new pattern match engine 1325s [test_pbx.c:test_exten:183]: Successfully matched 2000 to exten 2000 in context test_pattern with the new pattern match engine 1325s [test_pbx.c:test_exten:183]: Successfully matched 2000 to exten 2000 in context test_pattern_include with the new pattern match engine 1325s END /main/pbx/ - pattern_match_test Time: <1ms Result: PASS 1325s START /main/pbx/ - test_substitution 1325s [test_substitution.c:test_substitution:244]: Testing variable substitution ... 1325s [test_substitution.c:test_chan_integer:65]: Tested '${CALLINGANI2}' . . . . . passed 1325s [test_substitution.c:test_chan_integer:65]: Tested '${CALLINGTON}' . . . . . passed 1325s [test_substitution.c:test_chan_integer:65]: Tested '${CALLINGTNS}' . . . . . passed 1325s [test_substitution.c:test_chan_integer_accessor:89]: Tested '${HANGUPCAUSE}' . . . . . passed 1325s [test_substitution.c:test_chan_integer_accessor:89]: Tested '${PRIORITY}' . . . . . passed 1325s [test_substitution.c:test_chan_string:115]: Tested '${CONTEXT}' . . . . . passed 1325s [test_substitution.c:test_chan_string:115]: Tested '${EXTEN}' . . . . . passed 1325s [test_substitution.c:test_chan_variable:144]: Tested '${CHANNEL(language)}' . . . . . passed 1325s [test_substitution.c:test_chan_variable:144]: Tested '${CHANNEL(musicclass)}' . . . . . passed 1325s [test_substitution.c:test_chan_variable:144]: Tested '${CHANNEL(parkinglot)}' . . . . . passed 1325s [test_substitution.c:test_chan_variable:144]: Tested '${CALLERID(name)}' . . . . . passed 1325s [test_substitution.c:test_chan_variable:144]: Tested '${CURLOPT(proxyuserpwd)}' . . . . . passed 1325s [test_substitution.c:test_chan_variable:144]: Tested '${CDR(foo)}' . . . . . passed 1325s [test_substitution.c:test_chan_variable:144]: Tested '${ENV(foo)}' . . . . . passed 1325s [test_substitution.c:test_chan_variable:144]: Tested '${GLOBAL(foo)}' . . . . . passed 1325s [test_substitution.c:test_chan_variable:144]: Tested '${GROUP()}' . . . . . passed 1325s [test_substitution.c:test_2way_function:193]: Tested '${AES_ENCRYPT(abcdefghijklmnop,)}' and '${AES_DECRYPT(abcdefghijklmnop,)}' . . . . . passed 1325s [test_substitution.c:test_2way_function:193]: Tested '${BASE64_ENCODE()}' and '${BASE64_DECODE()}' . . . . . passed 1325s [test_substitution.c:test_expected_result:215]: Tested '123123' ('${foo}${foo}') == '123123' . . . . . passed 1325s [test_substitution.c:test_expected_result:215]: Tested 'A123A123A' ('A${foo}A${foo}A') == 'A123A123A' . . . . . passed 1325s [test_substitution.c:test_expected_result:215]: Tested 'A123A' ('A${${bar}}A') == 'A123A' . . . . . passed 1325s [test_substitution.c:test_expected_result:215]: Tested 'A123A' ('A${${baz}o}A') == 'A123A' . . . . . passed 1325s [test_substitution.c:test_expected_result:215]: Tested 'A23A' ('A${${baz}o:1}A') == 'A23A' . . . . . passed 1325s [test_substitution.c:test_expected_result:215]: Tested 'A2A' ('A${${baz}o:1:1}A') == 'A2A' . . . . . passed 1325s [test_substitution.c:test_expected_result:215]: Tested 'A2A' ('A${${baz}o:1:-1}A') == 'A2A' . . . . . passed 1325s [test_substitution.c:test_expected_result:215]: Tested 'A3A' ('A${${baz}o:-1:1}A') == 'A3A' . . . . . passed 1325s [test_substitution.c:test_expected_result:215]: Tested 'A2A' ('A${${baz}o:-2:1}A') == 'A2A' . . . . . passed 1325s [test_substitution.c:test_expected_result:215]: Tested 'A2A' ('A${${baz}o:-2:-1}A') == 'A2A' . . . . . passed 1325s [test_substitution.c:test_expected_result:215]: Tested 'cd&ef' ('${LISTFILTER(list1,&,ab)}') == 'cd&ef' . . . . . passed 1325s [test_substitution.c:test_expected_result:215]: Tested 'ab&ef' ('${LISTFILTER(list1,&,cd)}') == 'ab&ef' . . . . . passed 1325s [test_substitution.c:test_expected_result:215]: Tested 'ab&cd' ('${LISTFILTER(list1,&,ef)}') == 'ab&cd' . . . . . passed 1325s [test_substitution.c:test_expected_result:215]: Tested 'ab&cd&ef' ('${LISTFILTER(list1,&,gh)}') == 'ab&cd&ef' . . . . . passed 1325s [test_substitution.c:test_expected_result:215]: Tested 'ab&cd&ef' ('${LISTFILTER(list1,&,c)}') == 'ab&cd&ef' . . . . . passed 1325s [test_substitution.c:test_expected_result:215]: Tested 'ab&cd&ef' ('${LISTFILTER(list1,&,d)}') == 'ab&cd&ef' . . . . . passed 1325s [test_substitution.c:test_expected_result:215]: Tested '' ('${LISTFILTER(list2,&,ab)}') == '' . . . . . passed 1325s [test_substitution.c:test_expected_result:215]: Tested '' ('${LISTFILTER(list_empty,&,ab)}') == '' . . . . . passed 1325s [test_substitution.c:test_expected_result:215]: Tested '123,456' ('${SHELL(printf '%d' 123)},${SHELL(printf '%d' 456)}') == '123,456' . . . . . passed 1325s [test_substitution.c:test_expected_result:215]: Tested '123,,456' ('${foo},${CDR(answer)},${SHELL(printf '%d' 456)}') == '123,,456' . . . . . passed 1325s [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 1325s [test_substitution.c:test_expected_result:215]: Tested '123,,' ('${foo},${this_does_not_exist},${THIS_DOES_NOT_EXIST(either)}') == '123,,' . . . . . passed 1325s [test_substitution.c:test_chan_function:168]: Tested '${BLACKLIST(foo)}' . . . . . passed 1325s [test_substitution.c:test_chan_function:168]: Tested '${EVAL(foo)}' . . . . . passed 1325s [test_substitution.c:test_chan_function:168]: Tested '${FIELDNUM(foo)}' . . . . . passed 1325s [test_substitution.c:test_chan_function:168]: Tested '${FIELDQTY(foo)}' . . . . . passed 1325s [test_substitution.c:test_chan_function:168]: Tested '${HASHKEYS(foo)}' . . . . . passed 1325s [test_substitution.c:test_chan_function:168]: Tested '${IMPORT(foo)}' . . . . . passed 1325s [test_substitution.c:test_chan_function:168]: Tested '${PP_EACH_USER(foo)}' . . . . . passed 1325s [test_substitution.c:test_chan_function:168]: Tested '${TOLOWER(foo)}' . . . . . passed 1325s [test_substitution.c:test_chan_function:168]: Tested '${TOUPPER(foo)}' . . . . . passed 1325s END /main/pbx/ - test_substitution Time: 13ms Result: PASS 1325s START /main/pbx/ - variable_substrings 1325s END /main/pbx/ - variable_substrings Time: <1ms Result: PASS 1325s START /main/poll/ - poll_test 1325s [test_poll.c:poll_test:95]: Creating handle that should NEVER block on write 1325s [test_poll.c:poll_test:101]: Creating handle that should NEVER block on read 1325s [test_poll.c:poll_test:108]: Creating handle that should block on read 1325s [test_poll.c:poll_test:168]: Starting thread to ensure we don't block forever 1325s [test_poll.c:poll_test:194]: Cancelling failsafe thread. 1325s END /main/poll/ - poll_test Time: <1ms Result: PASS 1325s START /main/presence/ - channel_presence 1325s END /main/presence/ - channel_presence Time: <1ms Result: PASS 1325s START /main/sample/ - sample_test 1325s [test_skel.c:sample_test:57]: Executing sample test... 1325s END /main/sample/ - sample_test Time: <1ms Result: PASS 1325s START /main/sched/ - sched_test_freebird 1325s [test_sched.c:sched_test_freebird:440]: Received signal, calling Scedule and UNREF 1325s [test_sched.c:sched_test_freebird:441]: ID: 1 1328s [test_sched.c:sched_test_freebird:448]: Correct number of references '2' 1328s END /main/sched/ - sched_test_freebird Time: 3000ms Result: PASS 1328s START /main/sched/ - sched_test_order 1329s END /main/sched/ - sched_test_order Time: 400ms Result: PASS 1329s START /main/sorcery/ - wizard_read_only 1329s END /main/sorcery/ - wizard_read_only Time: <1ms Result: PASS 1329s START /main/sorcery/ - wizard_observation 1329s END /main/sorcery/ - wizard_observation Time: <1ms Result: PASS 1329s START /main/sorcery/ - instance_observation 1329s END /main/sorcery/ - instance_observation Time: <1ms Result: PASS 1329s START /main/sorcery/ - global_observation 1329s END /main/sorcery/ - global_observation Time: <1ms Result: PASS 1329s START /main/sorcery/ - object_field_registered 1329s END /main/sorcery/ - object_field_registered Time: <1ms Result: PASS 1329s START /main/sorcery/ - dialplan_function 1329s END /main/sorcery/ - dialplan_function Time: <1ms Result: PASS 1329s START /main/sorcery/ - configuration_file_wizard_retrieve_multiple_all 1329s END /main/sorcery/ - configuration_file_wizard_retrieve_multiple_all Time: <1ms Result: PASS 1329s START /main/sorcery/ - configuration_file_wizard_retrieve_multiple 1329s END /main/sorcery/ - configuration_file_wizard_retrieve_multiple Time: <1ms Result: PASS 1329s START /main/sorcery/ - configuration_file_wizard_retrieve_field 1329s END /main/sorcery/ - configuration_file_wizard_retrieve_field Time: <1ms Result: PASS 1329s START /main/sorcery/ - configuration_file_wizard_with_criteria 1329s END /main/sorcery/ - configuration_file_wizard_with_criteria Time: <1ms Result: PASS 1329s START /main/sorcery/ - configuration_file_wizard_with_file_integrity 1329s END /main/sorcery/ - configuration_file_wizard_with_file_integrity Time: <1ms Result: PASS 1329s START /main/sorcery/ - configuration_file_wizard 1329s END /main/sorcery/ - configuration_file_wizard Time: <1ms Result: PASS 1329s START /main/sorcery/ - object_type_observer 1329s END /main/sorcery/ - object_type_observer Time: <1ms Result: PASS 1329s START /main/sorcery/ - caching_wizard_behavior 1329s END /main/sorcery/ - caching_wizard_behavior Time: <1ms Result: PASS 1329s START /main/sorcery/ - object_is_stale 1329s END /main/sorcery/ - object_is_stale Time: <1ms Result: PASS 1329s START /main/sorcery/ - object_delete_uncreated 1329s END /main/sorcery/ - object_delete_uncreated Time: <1ms Result: PASS 1329s START /main/sorcery/ - object_delete 1329s END /main/sorcery/ - object_delete Time: <1ms Result: PASS 1329s START /main/sorcery/ - object_update_uncreated 1329s END /main/sorcery/ - object_update_uncreated Time: <1ms Result: PASS 1329s START /main/sorcery/ - object_update 1329s END /main/sorcery/ - object_update Time: <1ms Result: PASS 1329s START /main/sorcery/ - object_retrieve_regex 1329s END /main/sorcery/ - object_retrieve_regex Time: <1ms Result: PASS 1329s START /main/sorcery/ - object_retrieve_multiple_field 1329s END /main/sorcery/ - object_retrieve_multiple_field Time: <1ms Result: PASS 1329s START /main/sorcery/ - object_retrieve_multiple_all 1329s END /main/sorcery/ - object_retrieve_multiple_all Time: <1ms Result: PASS 1329s START /main/sorcery/ - object_retrieve_field 1329s END /main/sorcery/ - object_retrieve_field Time: <1ms Result: PASS 1329s START /main/sorcery/ - object_retrieve_id 1329s END /main/sorcery/ - object_retrieve_id Time: <1ms Result: PASS 1329s START /main/sorcery/ - object_create 1329s END /main/sorcery/ - object_create Time: <1ms Result: PASS 1329s START /main/sorcery/ - changeset_create_unchanged 1329s END /main/sorcery/ - changeset_create_unchanged Time: <1ms Result: PASS 1329s START /main/sorcery/ - changeset_create 1329s END /main/sorcery/ - changeset_create Time: <1ms Result: PASS 1329s START /main/sorcery/ - extended_fields 1329s END /main/sorcery/ - extended_fields Time: <1ms Result: PASS 1329s START /main/sorcery/ - objectset_apply_fields 1329s END /main/sorcery/ - objectset_apply_fields Time: <1ms Result: PASS 1329s START /main/sorcery/ - objectset_transform 1329s END /main/sorcery/ - objectset_transform Time: <1ms Result: PASS 1329s START /main/sorcery/ - objectset_apply_invalid 1329s END /main/sorcery/ - objectset_apply_invalid Time: <1ms Result: PASS 1329s START /main/sorcery/ - objectset_apply_handler 1329s END /main/sorcery/ - objectset_apply_handler Time: <1ms Result: PASS 1329s START /main/sorcery/ - objectset_apply 1329s END /main/sorcery/ - objectset_apply Time: <1ms Result: PASS 1329s START /main/sorcery/ - objectset_create_regex 1329s END /main/sorcery/ - objectset_create_regex Time: <1ms Result: PASS 1329s START /main/sorcery/ - objectset_json_create 1329s END /main/sorcery/ - objectset_json_create Time: <1ms Result: PASS 1329s START /main/sorcery/ - objectset_create 1329s END /main/sorcery/ - objectset_create Time: <1ms Result: PASS 1329s START /main/sorcery/ - object_diff_native 1329s END /main/sorcery/ - object_diff_native Time: <1ms Result: PASS 1329s START /main/sorcery/ - object_diff 1329s END /main/sorcery/ - object_diff Time: <1ms Result: PASS 1329s START /main/sorcery/ - object_copy_native 1329s END /main/sorcery/ - object_copy_native Time: <1ms Result: PASS 1329s START /main/sorcery/ - object_copy 1329s END /main/sorcery/ - object_copy Time: <1ms Result: PASS 1329s START /main/sorcery/ - object_alloc_without_id 1329s END /main/sorcery/ - object_alloc_without_id Time: <1ms Result: PASS 1329s START /main/sorcery/ - object_alloc_with_id 1329s END /main/sorcery/ - object_alloc_with_id Time: <1ms Result: PASS 1329s START /main/sorcery/ - object_fields_register 1329s END /main/sorcery/ - object_fields_register Time: <1ms Result: PASS 1329s START /main/sorcery/ - object_field_register 1329s END /main/sorcery/ - object_field_register Time: <1ms Result: PASS 1329s START /main/sorcery/ - object_register_without_mapping 1329s END /main/sorcery/ - object_register_without_mapping Time: <1ms Result: PASS 1329s START /main/sorcery/ - object_register 1329s END /main/sorcery/ - object_register Time: <1ms Result: PASS 1329s START /main/sorcery/ - apply_config 1329s END /main/sorcery/ - apply_config Time: <1ms Result: PASS 1329s START /main/sorcery/ - apply_default 1329s END /main/sorcery/ - apply_default Time: <1ms Result: PASS 1329s START /main/sorcery/ - open 1329s END /main/sorcery/ - open Time: <1ms Result: PASS 1329s START /main/sorcery/ - wizard_registration 1329s END /main/sorcery/ - wizard_registration Time: <1ms Result: PASS 1329s START /main/sorcery/ - wizard_apply_and_insert 1329s END /main/sorcery/ - wizard_apply_and_insert Time: <1ms Result: PASS 1329s START /main/stdtime/ - time_create_by_unit_str 1329s END /main/stdtime/ - time_create_by_unit_str Time: <1ms Result: PASS 1329s START /main/stdtime/ - time_create_by_unit 1329s END /main/stdtime/ - time_create_by_unit Time: <1ms Result: PASS 1329s START /main/stdtime/ - time_str_to_unit 1329s END /main/stdtime/ - time_str_to_unit Time: <1ms Result: PASS 1329s START /main/stdtime/ - time_tv_to_usec 1329s END /main/stdtime/ - time_tv_to_usec Time: <1ms Result: PASS 1329s START /main/stdtime/ - timezone_watch 1329s [test_time.c:test_timezone_watch:82]: Executing deletion test... 1329s [test_time.c:test_timezone_watch:90]: Querying timezone /tmp/timezone.3QF8Gc/test 1330s [test_time.c:test_timezone_watch:90]: Querying timezone /tmp/timezone.3QF8Gc/test 1330s [test_time.c:test_timezone_watch:82]: Executing symlink test... 1330s [test_time.c:test_timezone_watch:90]: Querying timezone /tmp/timezone.3QF8Gc/test 1331s [test_time.c:test_timezone_watch:90]: Querying timezone /tmp/timezone.3QF8Gc/test 1331s END /main/stdtime/ - timezone_watch Time: 2286ms Result: PASS 1331s START /main/stream/ - stream_topology_map_create 1331s END /main/stream/ - stream_topology_map_create Time: <1ms Result: PASS 1331s START /main/stream/ - format_cap_from_stream_topology 1331s END /main/stream/ - format_cap_from_stream_topology Time: <1ms Result: PASS 1331s START /main/stream/ - stream_topology_change_request_from_channel 1331s END /main/stream/ - stream_topology_change_request_from_channel Time: <1ms Result: PASS 1331s START /main/stream/ - stream_topology_change_request_from_application 1331s END /main/stream/ - stream_topology_change_request_from_application Time: <1ms Result: PASS 1331s START /main/stream/ - stream_topology_change_request_from_channel_non_multistream 1331s END /main/stream/ - stream_topology_change_request_from_channel_non_multistream Time: <1ms Result: PASS 1331s START /main/stream/ - stream_topology_change_request_from_application_non_multistream 1331s END /main/stream/ - stream_topology_change_request_from_application_non_multistream Time: <1ms Result: PASS 1331s START /main/stream/ - stream_read_multistream 1331s [test_stream.c:read_test:1726]: ChanType: MULTI ReadType: NON-STREAM Streams: 2 Frames: 16 Frames per read: 1 Expected Nulls: 0 1331s [test_stream.c:read_test:1759]: Frames read: 16 NULL frames: 0 1331s [test_stream.c:read_test:1726]: ChanType: MULTI ReadType: STREAM Streams: 2 Frames: 16 Frames per read: 1 Expected Nulls: 0 1331s [test_stream.c:read_test:1759]: Frames read: 16 NULL frames: 0 1331s [test_stream.c:read_test:1726]: ChanType: MULTI ReadType: NON-STREAM Streams: 4 Frames: 16 Frames per read: 1 Expected Nulls: 8 1331s [test_stream.c:read_test:1759]: Frames read: 16 NULL frames: 8 1331s [test_stream.c:read_test:1726]: ChanType: MULTI ReadType: STREAM Streams: 4 Frames: 16 Frames per read: 1 Expected Nulls: 0 1331s [test_stream.c:read_test:1759]: Frames read: 16 NULL frames: 0 1331s [test_stream.c:read_test:1726]: ChanType: MULTI ReadType: NON-STREAM Streams: 2 Frames: 16 Frames per read: 3 Expected Nulls: 0 1331s [test_stream.c:read_test:1759]: Frames read: 16 NULL frames: 0 1331s [test_stream.c:read_test:1726]: ChanType: MULTI ReadType: STREAM Streams: 2 Frames: 16 Frames per read: 3 Expected Nulls: 0 1331s [test_stream.c:read_test:1759]: Frames read: 16 NULL frames: 0 1331s [test_stream.c:read_test:1726]: ChanType: MULTI ReadType: NON-STREAM Streams: 4 Frames: 16 Frames per read: 3 Expected Nulls: 8 1331s [test_stream.c:read_test:1759]: Frames read: 16 NULL frames: 8 1331s [test_stream.c:read_test:1726]: ChanType: MULTI ReadType: STREAM Streams: 4 Frames: 16 Frames per read: 3 Expected Nulls: 0 1331s [test_stream.c:read_test:1759]: Frames read: 16 NULL frames: 0 1331s END /main/stream/ - stream_read_multistream Time: <1ms Result: PASS 1331s START /main/stream/ - stream_read_non_multistream 1331s [test_stream.c:read_test:1726]: ChanType: NON-MULTI ReadType: NON-STREAM Streams: 2 Frames: 16 Frames per read: 1 Expected Nulls: 0 1331s [test_stream.c:read_test:1759]: Frames read: 16 NULL frames: 0 1331s [test_stream.c:read_test:1726]: ChanType: NON-MULTI ReadType: STREAM Streams: 2 Frames: 16 Frames per read: 1 Expected Nulls: 0 1331s [test_stream.c:read_test:1759]: Frames read: 16 NULL frames: 0 1331s [test_stream.c:read_test:1726]: ChanType: NON-MULTI ReadType: NON-STREAM Streams: 2 Frames: 16 Frames per read: 3 Expected Nulls: 0 1331s [test_stream.c:read_test:1759]: Frames read: 16 NULL frames: 0 1331s [test_stream.c:read_test:1726]: ChanType: NON-MULTI ReadType: STREAM Streams: 2 Frames: 16 Frames per read: 3 Expected Nulls: 0 1331s [test_stream.c:read_test:1759]: Frames read: 16 NULL frames: 0 1331s END /main/stream/ - stream_read_non_multistream Time: <1ms Result: PASS 1331s START /main/stream/ - stream_write_multistream 1331s END /main/stream/ - stream_write_multistream Time: <1ms Result: PASS 1331s START /main/stream/ - stream_write_non_multistream 1331s END /main/stream/ - stream_write_non_multistream Time: <1ms Result: PASS 1331s START /main/stream/ - stream_topology_channel_set 1331s END /main/stream/ - stream_topology_channel_set Time: <1ms Result: PASS 1331s START /main/stream/ - stream_topology_create_from_channel_nativeformats 1331s END /main/stream/ - stream_topology_create_from_channel_nativeformats Time: <1ms Result: PASS 1331s START /main/stream/ - stream_topology_get_first_stream_by_type 1331s END /main/stream/ - stream_topology_get_first_stream_by_type Time: <1ms Result: PASS 1331s START /main/stream/ - stream_topology_create_from_format_cap 1331s END /main/stream/ - stream_topology_create_from_format_cap Time: <1ms Result: PASS 1331s START /main/stream/ - stream_topology_del_stream 1331s END /main/stream/ - stream_topology_del_stream Time: <1ms Result: PASS 1331s START /main/stream/ - stream_topology_set_stream 1331s END /main/stream/ - stream_topology_set_stream Time: <1ms Result: PASS 1331s START /main/stream/ - stream_topology_append_stream 1331s END /main/stream/ - stream_topology_append_stream Time: <1ms Result: PASS 1331s START /main/stream/ - stream_topology_clone 1331s END /main/stream/ - stream_topology_clone Time: <1ms Result: PASS 1331s START /main/stream/ - stream_topology_create 1331s END /main/stream/ - stream_topology_create Time: <1ms Result: PASS 1331s START /main/stream/ - stream_metadata 1331s END /main/stream/ - stream_metadata Time: <1ms Result: PASS 1331s START /main/stream/ - stream_set_state 1331s END /main/stream/ - stream_set_state Time: <1ms Result: PASS 1331s START /main/stream/ - stream_set_formats 1331s END /main/stream/ - stream_set_formats Time: <1ms Result: PASS 1331s START /main/stream/ - stream_set_type 1331s END /main/stream/ - stream_set_type Time: <1ms Result: PASS 1331s START /main/stream/ - stream_create_no_name 1331s END /main/stream/ - stream_create_no_name Time: <1ms Result: PASS 1331s START /main/stream/ - stream_create 1331s END /main/stream/ - stream_create Time: <1ms Result: PASS 1331s START /main/strings/ - in_delimited_string 1331s END /main/strings/ - in_delimited_string Time: <1ms Result: PASS 1331s START /main/strings/ - temp_strings 1331s END /main/strings/ - temp_strings Time: <1ms Result: PASS 1331s START /main/strings/ - strings_match 1331s END /main/strings/ - strings_match Time: <1ms Result: PASS 1331s START /main/strings/ - escape 1331s END /main/strings/ - escape Time: <1ms Result: PASS 1331s START /main/strings/ - escape_semicolons 1331s END /main/strings/ - escape_semicolons Time: <1ms Result: PASS 1331s START /main/strings/ - strsep_quoted 1331s END /main/strings/ - strsep_quoted Time: <1ms Result: PASS 1331s START /main/strings/ - strsep 1331s END /main/strings/ - strsep Time: <1ms Result: PASS 1331s START /main/strings/ - ends_with 1331s END /main/strings/ - ends_with Time: <1ms Result: PASS 1331s START /main/strings/ - begins_with 1331s END /main/strings/ - begins_with Time: <1ms Result: PASS 1331s START /main/strings/ - str_test 1331s END /main/strings/ - str_test Time: <1ms Result: PASS 1331s START /main/taskprocessor/ - serializer_pool 1335s END /main/taskprocessor/ - serializer_pool Time: 4000ms Result: PASS 1335s START /main/taskprocessor/ - taskprocessor_push_local 1335s END /main/taskprocessor/ - taskprocessor_push_local Time: <1ms Result: PASS 1335s START /main/taskprocessor/ - taskprocessor_shutdown 1335s END /main/taskprocessor/ - taskprocessor_shutdown Time: <1ms Result: PASS 1335s START /main/taskprocessor/ - taskprocessor_listener 1335s END /main/taskprocessor/ - taskprocessor_listener Time: <1ms Result: PASS 1335s START /main/taskprocessor/ - subsystem_alert 1335s [test_taskprocessor.c:subsystem_alert:224]: Pushing task 1 1335s [test_taskprocessor.c:subsystem_alert:224]: Pushing task 2 1335s [test_taskprocessor.c:subsystem_alert:224]: Pushing task 3 1335s [test_taskprocessor.c:subsystem_alert:224]: Pushing task 4 1335s [test_taskprocessor.c:subsystem_alert:224]: Pushing task 5 1335s [test_taskprocessor.c:subsystem_alert:224]: Pushing task 6 1335s [test_taskprocessor.c:subsystem_alert:224]: Pushing task 7 1335s [test_taskprocessor.c:subsystem_alert:237]: Subsystem alert triggered correctly at 6 1335s [test_taskprocessor.c:subsystem_alert:240]: Global alert triggered correctly at 6 1335s [test_taskprocessor.c:subsystem_alert:224]: Pushing task 8 1335s [test_taskprocessor.c:subsystem_alert:224]: Pushing task 9 1335s [test_taskprocessor.c:subsystem_alert:224]: Pushing task 10 1335s [test_taskprocessor.c:subsystem_alert:266]: Waiting on task 1 1335s [test_taskprocessor.c:subsystem_alert:266]: Waiting on task 2 1336s [test_taskprocessor.c:subsystem_alert:266]: Waiting on task 3 1336s [test_taskprocessor.c:subsystem_alert:266]: Waiting on task 4 1337s [test_taskprocessor.c:subsystem_alert:266]: Waiting on task 5 1337s [test_taskprocessor.c:subsystem_alert:266]: Waiting on task 6 1338s [test_taskprocessor.c:subsystem_alert:279]: Subsystem alert cleared correctly at 3 1338s [test_taskprocessor.c:subsystem_alert:282]: Global alert cleared correctly at 3 1338s [test_taskprocessor.c:subsystem_alert:266]: Waiting on task 7 1338s [test_taskprocessor.c:subsystem_alert:266]: Waiting on task 8 1339s [test_taskprocessor.c:subsystem_alert:266]: Waiting on task 9 1339s [test_taskprocessor.c:subsystem_alert:266]: Waiting on task 10 1340s END /main/taskprocessor/ - subsystem_alert Time: 5001ms Result: PASS 1340s START /main/taskprocessor/ - default_taskprocessor_load 1340s END /main/taskprocessor/ - default_taskprocessor_load Time: 34ms Result: PASS 1340s START /main/taskprocessor/ - default_taskprocessor 1340s END /main/taskprocessor/ - default_taskprocessor Time: <1ms Result: PASS 1340s START /main/test/ - registrations 1340s END /main/test/ - registrations Time: <1ms Result: PASS 1340s START /main/test_capture/ - test_capture_false 1340s [test_capture.c:test_capture_false:120]: Executing false exit test... 1340s END /main/test_capture/ - test_capture_false Time: 16ms Result: PASS 1340s START /main/test_capture/ - test_capture_true 1340s [test_capture.c:test_capture_true:61]: Executing true exit test... 1340s END /main/test_capture/ - test_capture_true Time: 14ms Result: PASS 1340s START /main/test_capture/ - test_capture_stdout_stderr 1340s [test_capture.c:test_capture_stdout_stderr:318]: Executing stdout/stderr test... 1340s END /main/test_capture/ - test_capture_stdout_stderr Time: 13ms Result: PASS 1340s START /main/test_capture/ - test_capture_with_dynamic 1340s [test_capture.c:test_capture_with_dynamic:249]: Executing dynamic argument test... 1340s END /main/test_capture/ - test_capture_with_dynamic Time: 14ms Result: PASS 1340s START /main/test_capture/ - test_capture_with_stdin 1340s [test_capture.c:test_capture_with_stdin:183]: Executing stdin test... 1340s END /main/test_capture/ - test_capture_with_stdin Time: 17ms Result: PASS 1340s START /main/threadpool/ - threadpool_serializer_dupe 1340s END /main/threadpool/ - threadpool_serializer_dupe Time: <1ms Result: PASS 1340s START /main/threadpool/ - threadpool_serializer 1341s END /main/threadpool/ - threadpool_serializer Time: 1000ms Result: PASS 1341s START /main/threadpool/ - more_destruction 1341s END /main/threadpool/ - more_destruction Time: <1ms Result: PASS 1341s START /main/threadpool/ - task_distribution 1341s END /main/threadpool/ - task_distribution Time: <1ms Result: PASS 1341s START /main/threadpool/ - reactivation 1341s END /main/threadpool/ - reactivation Time: <1ms Result: PASS 1341s START /main/threadpool/ - max_size 1341s END /main/threadpool/ - max_size Time: <1ms Result: PASS 1341s START /main/threadpool/ - auto_increment 1341s END /main/threadpool/ - auto_increment Time: <1ms Result: PASS 1341s START /main/threadpool/ - one_thread_multiple_tasks 1341s END /main/threadpool/ - one_thread_multiple_tasks Time: <1ms Result: PASS 1341s START /main/threadpool/ - one_thread_one_task 1341s END /main/threadpool/ - one_thread_one_task Time: <1ms Result: PASS 1341s START /main/threadpool/ - one_task_one_thread 1341s END /main/threadpool/ - one_task_one_thread Time: <1ms Result: PASS 1341s START /main/threadpool/ - thread_timeout_thrash 1372s END /main/threadpool/ - thread_timeout_thrash Time: 31009ms Result: PASS 1372s START /main/threadpool/ - thread_timeout 1374s END /main/threadpool/ - thread_timeout Time: 2000ms Result: PASS 1374s START /main/threadpool/ - thread_destruction 1374s END /main/threadpool/ - thread_destruction Time: <1ms Result: PASS 1374s START /main/threadpool/ - thread_creation 1374s END /main/threadpool/ - thread_creation Time: <1ms Result: PASS 1374s START /main/threadpool/ - initial_threads 1374s END /main/threadpool/ - initial_threads Time: <1ms Result: PASS 1374s START /main/threadpool/ - push 1374s END /main/threadpool/ - push Time: <1ms Result: PASS 1374s START /main/uri/ - uri_default_http_secure 1374s END /main/uri/ - uri_default_http_secure Time: <1ms Result: PASS 1374s START /main/uri/ - uri_default_http 1374s END /main/uri/ - uri_default_http Time: <1ms Result: PASS 1374s START /main/uri/ - uri_parse 1374s END /main/uri/ - uri_parse Time: <1ms Result: PASS 1374s START /main/utf8/ - replace_invalid 1374s END /main/utf8/ - replace_invalid Time: <1ms Result: PASS 1374s START /main/utf8/ - utf8_validator 1374s END /main/utf8/ - utf8_validator Time: <1ms Result: PASS 1374s START /main/utf8/ - copy_string 1374s END /main/utf8/ - copy_string Time: <1ms Result: PASS 1374s START /main/utf8/ - is_valid 1374s END /main/utf8/ - is_valid Time: <1ms Result: PASS 1374s START /main/utils/ - quote_unescaping 1374s END /main/utils/ - quote_unescaping Time: <1ms Result: PASS 1374s START /main/utils/ - quote_mutation 1374s END /main/utils/ - quote_mutation Time: <1ms Result: PASS 1374s START /main/utils/ - crypt_test 1374s END /main/utils/ - crypt_test Time: 17ms Result: PASS 1374s START /main/utils/ - safe_mkdir_test 1374s END /main/utils/ - safe_mkdir_test Time: 1ms Result: PASS 1374s START /main/utils/ - base64_test 1374s END /main/utils/ - base64_test Time: <1ms Result: PASS 1374s START /main/utils/ - sha1_test 1374s [test_utils.c:sha1_test:250]: Testing SHA1 ... 1374s END /main/utils/ - sha1_test Time: <1ms Result: PASS 1374s START /main/utils/ - md5_test 1374s [test_utils.c:md5_test:205]: Testing MD5 ... 1374s END /main/utils/ - md5_test Time: <1ms Result: PASS 1374s START /main/utils/ - quoted_escape_test 1374s END /main/utils/ - quoted_escape_test Time: <1ms Result: PASS 1374s START /main/utils/ - uri_encode_decode_test 1374s END /main/utils/ - uri_encode_decode_test Time: <1ms Result: PASS 1374s START /main/utils/ - string_field_aggregate_test 1374s [test_stringfields.c:string_field_aggregate_test:392]: Structures 3 embedded pool initialized successfully. 1374s [test_stringfields.c:string_field_aggregate_test:410]: Structures 3 additional pool initialized successfully. 1374s [test_stringfields.c:string_field_aggregate_test:422]: Structures 1/2 are equal as expected. 1374s [test_stringfields.c:string_field_aggregate_test:430]: Structures 1/3 are different as expected. 1374s [test_stringfields.c:string_field_aggregate_test:438]: Structures 2/3 are different as expected. 1374s [test_stringfields.c:string_field_aggregate_test:446]: Structures 3/4 are different as expected. 1374s [test_stringfields.c:string_field_aggregate_test:454]: Copying from structure 3 to structure 1 succeeded! 1374s [test_stringfields.c:string_field_aggregate_test:463]: Structures 1/3 are equal as expected. 1374s [test_stringfields.c:string_field_aggregate_test:470]: Structures 1/2 are different as expected. 1374s [test_stringfields.c:string_field_aggregate_test:473]: Reset but don't free. 1374s [test_stringfields.c:string_field_aggregate_test:484]: Structures 1/2 are the same (empty) as expected. 1374s [test_stringfields.c:string_field_aggregate_test:492]: Structure 4 embedded pool is the current pool as expected. 1374s [test_stringfields.c:string_field_aggregate_test:500]: Structure 4 embedded pool does not have a previous as expected. 1374s END /main/utils/ - string_field_aggregate_test Time: <1ms Result: PASS 1374s START /main/utils/ - string_field_test 1374s [test_stringfields.c:string_field_test:79]: First things first. Let's see if we can actually allocate string fields 1374s [test_stringfields.c:string_field_test:85]: All right! Successfully allocated! Now let's get down to business 1374s [test_stringfields.c:string_field_test:89]: We're going to set some string fields and perform some checks 1374s [test_stringfields.c:string_field_test:94]: First we're going to make sure that the strings are actually set to what we expect 1374s [test_stringfields.c:string_field_test:100]: test_struct.string1 appears to be all clear. It has 'elephant' and that's what we expect 1374s [test_stringfields.c:string_field_test:107]: test_struct.string2 appears to be all clear. It has 'hippopotamus' and that's what we expect 1374s [test_stringfields.c:string_field_test:110]: Now let's make sure that our recorded capacities for these strings is what we expect 1374s [test_stringfields.c:string_field_test:117]: string1 has the allocation area we expect: 9 1374s [test_stringfields.c:string_field_test:125]: string2 has the allocation area we expect: 13 1374s [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 1374s [test_stringfields.c:string_field_test:137]: string1 successfully was changed to 'rhino' 1374s [test_stringfields.c:string_field_test:144]: Shrinking string1 allowed it to stay in the same place in memory 1374s [test_stringfields.c:string_field_test:151]: Shrinking string1 did not change its allocation area (This is a good thing) 1374s [test_stringfields.c:string_field_test:154]: Next, let's increase it a little but not all the way to its original size 1374s [test_stringfields.c:string_field_test:163]: string1 successfully was changed to 'mammoth' 1374s [test_stringfields.c:string_field_test:170]: Expanding string1 allowed it to stay in the same place in memory 1374s [test_stringfields.c:string_field_test:177]: Expanding string1 did not change its allocation area (This is a good thing) 1374s [test_stringfields.c:string_field_test:180]: Cool, now let's bring it back to its original size and see what happens 1374s [test_stringfields.c:string_field_test:188]: string1 successfully changed to 'elephant' 1374s [test_stringfields.c:string_field_test:195]: Restoring string1 did not cause it to move (This is a good thing) 1374s [test_stringfields.c:string_field_test:202]: The allocation amount for string1 is still holding steady 1374s [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 1374s [test_stringfields.c:string_field_test:214]: string2 successfully changed to 'hippopotamus face' 1374s [test_stringfields.c:string_field_test:222]: The allocation amount successfully increased for string2 when it grew 1374s [test_stringfields.c:string_field_test:229]: string2 stayed in place when it grew. Good job! 1374s [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 1374s [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' 1374s [test_stringfields.c:string_field_test:248]: Good. Setting string1 to a long value caused it to change addresses 1374s [test_stringfields.c:string_field_test:256]: The stored allocation size of string1 is what we expect 1374s [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 1374s [test_stringfields.c:string_field_test:281]: Three different pools are linked as expected. 1374s [test_stringfields.c:string_field_test:289]: After removing a pool the remaining two are linked as expected. 1374s END /main/utils/ - string_field_test Time: <1ms Result: PASS 1374s START /main/uuid/ - uuid 1374s [test_uuid.c:uuid:59]: Generate UUID direct to string, got f4d6069d-53e8-426a-838f-10ac000902b2 1374s [test_uuid.c:uuid:90]: Second generated UUID converted to string, got cff0bd82-850d-4912-888e-d477ede0c867 1374s END /main/uuid/ - uuid Time: <1ms Result: PASS 1374s START /main/vector/ - basic 1374s END /main/vector/ - basic Time: <1ms Result: PASS 1374s START /main/vector/ - basic_integer 1374s END /main/vector/ - basic_integer Time: <1ms Result: PASS 1374s START /main/vector/ - callbacks 1374s END /main/vector/ - callbacks Time: <1ms Result: PASS 1374s START /main/vector/ - locks 1374s END /main/vector/ - locks Time: <1ms Result: PASS 1374s START /main/voicemail_api/ - off_nominal_msg_playback 1374s [test_voicemail_api.c:voicemail_api_off_nominal_msg_playback:1495]: Created message in test_vm_api_1234/Old with ID 1712613122-909401725 1374s [test_voicemail_api.c:voicemail_api_off_nominal_msg_playback:1495]: Created message in test_vm_api_1234/INBOX with ID 1712613122-960311778 1374s [test_voicemail_api.c:voicemail_api_off_nominal_msg_playback:1495]: Created message in test_vm_api_2345/INBOX with ID 1712613122-1500739833 1374s [test_voicemail_api.c:voicemail_api_off_nominal_msg_playback:1495]: Created message in test_vm_api_2345/INBOX with ID 1712613122-719848782 1374s [test_voicemail_api.c:voicemail_api_off_nominal_msg_playback:1504]: Playing back message from invalid mailbox 1374s [test_voicemail_api.c:voicemail_api_off_nominal_msg_playback:1507]: Playing back message from NULL mailbox 1374s [test_voicemail_api.c:voicemail_api_off_nominal_msg_playback:1510]: Playing back message from invalid context 1374s [test_voicemail_api.c:voicemail_api_off_nominal_msg_playback:1513]: Playing back message from invalid folder 1374s [test_voicemail_api.c:voicemail_api_off_nominal_msg_playback:1516]: Playing back message from NULL folder 1374s [test_voicemail_api.c:voicemail_api_off_nominal_msg_playback:1519]: Playing back message with invalid message specifier 1374s [test_voicemail_api.c:voicemail_api_off_nominal_msg_playback:1522]: Playing back message with NULL message specifier 1374s END /main/voicemail_api/ - off_nominal_msg_playback Time: 14ms Result: PASS 1374s START /main/voicemail_api/ - nominal_msg_playback 1374s [test_voicemail_api.c:voicemail_api_nominal_msg_playback:1433]: Created message in test_vm_api_1234/Old with ID 1712613122-909401725 1374s [test_voicemail_api.c:voicemail_api_nominal_msg_playback:1433]: Created message in test_vm_api_1234/INBOX with ID 1712613122-960311778 1374s [test_voicemail_api.c:voicemail_api_nominal_msg_playback:1433]: Created message in test_vm_api_2345/INBOX with ID 1712613122-1500739833 1374s [test_voicemail_api.c:voicemail_api_nominal_msg_playback:1433]: Created message in test_vm_api_2345/INBOX with ID 1712613122-719848782 1374s [test_voicemail_api.c:voicemail_api_nominal_msg_playback:1445]: Playing back message from test_vm_api_1234 to mock channel 1375s [test_voicemail_api.c:voicemail_api_nominal_msg_playback:1448]: Playing back message from test_vm_api_2345 to callback function 1375s [test_voicemail_api.c:voicemail_api_nominal_msg_playback:1453]: Playing back message from test_vm_api_2345 to callback function with default context 1375s END /main/voicemail_api/ - nominal_msg_playback Time: 460ms Result: PASS 1375s START /main/voicemail_api/ - off_nominal_forward 1375s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1355]: Created message in test_vm_api_1234/Old with ID 1712613123-909401725 1375s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1355]: Created message in test_vm_api_1234/INBOX with ID 1712613123-960311778 1375s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1355]: Created message in test_vm_api_2345/INBOX with ID 1712613123-1500739833 1375s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1355]: Created message in test_vm_api_2345/INBOX with ID 1712613123-719848782 1375s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1364]: Test forwarding from an invalid mailbox 1375s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1367]: Test forwarding from a NULL mailbox 1375s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1370]: Test forwarding from an invalid context 1375s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1373]: Test forwarding from an invalid folder 1375s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1376]: Test forwarding from a NULL folder 1375s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1379]: Test forwarding to an invalid mailbox 1375s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1382]: Test forwarding to a NULL mailbox 1375s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1385]: Test forwarding to an invalid context 1375s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1388]: Test forwarding to an invalid folder 1375s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1392]: Test forwarding to a NULL folder 1375s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1395]: Test forwarding when no messages are select 1375s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1398]: Test forwarding a message that doesn't exist 1375s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1402]: Test forwarding multiple messages, where some messages don't exist 1375s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1405]: Test forwarding a message with an invalid size specifier 1375s END /main/voicemail_api/ - off_nominal_forward Time: 13ms Result: PASS 1375s START /main/voicemail_api/ - nominal_forward 1375s [test_voicemail_api.c:voicemail_api_nominal_forward:1239]: Created message in test_vm_api_1234/Old with ID 1712613123-909401725 1375s [test_voicemail_api.c:voicemail_api_nominal_forward:1239]: Created message in test_vm_api_1234/INBOX with ID 1712613123-960311778 1375s [test_voicemail_api.c:voicemail_api_nominal_forward:1239]: Created message in test_vm_api_2345/INBOX with ID 1712613123-1500739833 1375s [test_voicemail_api.c:voicemail_api_nominal_forward:1239]: Created message in test_vm_api_2345/INBOX with ID 1712613123-719848782 1375s [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 1375s [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 1375s [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 1375s [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 1375s [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 1375s END /main/voicemail_api/ - nominal_forward Time: 31ms Result: PASS 1375s START /main/voicemail_api/ - off_nominal_remove 1375s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1180]: Created message in test_vm_api_1234/Old with ID 1712613123-909401725 1375s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1180]: Created message in test_vm_api_1234/INBOX with ID 1712613123-960311778 1375s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1180]: Created message in test_vm_api_2345/INBOX with ID 1712613123-1500739833 1375s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1180]: Created message in test_vm_api_2345/INBOX with ID 1712613123-719848782 1375s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1186]: Test removing a single message with an invalid mailbox 1375s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1189]: Test removing a single message with a NULL mailbox 1375s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1192]: Test removing a single message with an invalid context 1375s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1195]: Test removing a single message with an invalid folder 1375s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1198]: Test removing a single message with a NULL folder 1375s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1201]: Test removing a single message with an invalid message number 1375s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1205]: Test removing multiple messages with a single invalid message number 1375s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1209]: Test removing no messages with no message numbers 1375s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1212]: Test removing multiple messages with an invalid size specifier 1375s END /main/voicemail_api/ - off_nominal_remove Time: 9ms Result: PASS 1375s START /main/voicemail_api/ - nominal_remove 1375s [test_voicemail_api.c:voicemail_api_nominal_remove:1133]: Created message in test_vm_api_1234/Old with ID 1712613123-909401725 1375s [test_voicemail_api.c:voicemail_api_nominal_remove:1133]: Created message in test_vm_api_1234/INBOX with ID 1712613123-960311778 1375s [test_voicemail_api.c:voicemail_api_nominal_remove:1133]: Created message in test_vm_api_2345/INBOX with ID 1712613123-1500739833 1375s [test_voicemail_api.c:voicemail_api_nominal_remove:1133]: Created message in test_vm_api_2345/INBOX with ID 1712613123-719848782 1375s [test_voicemail_api.c:voicemail_api_nominal_remove:1141]: Test removing a single message from INBOX 1375s [test_voicemail_api.c:voicemail_api_nominal_remove:1144]: Test removing a single message from Old 1375s [test_voicemail_api.c:voicemail_api_nominal_remove:1147]: Test removing multiple messages from INBOX 1375s END /main/voicemail_api/ - nominal_remove Time: 10ms Result: PASS 1375s START /main/voicemail_api/ - off_nominal_move 1375s [test_voicemail_api.c:voicemail_api_off_nominal_move:1061]: Created message in test_vm_api_1234/Old with ID 1712613123-909401725 1375s [test_voicemail_api.c:voicemail_api_off_nominal_move:1061]: Created message in test_vm_api_1234/INBOX with ID 1712613123-960311778 1375s [test_voicemail_api.c:voicemail_api_off_nominal_move:1061]: Created message in test_vm_api_2345/INBOX with ID 1712613123-1500739833 1375s [test_voicemail_api.c:voicemail_api_off_nominal_move:1061]: Created message in test_vm_api_2345/INBOX with ID 1712613123-719848782 1375s [test_voicemail_api.c:voicemail_api_off_nominal_move:1070]: Test move attempt for invalid mailbox test_vm_3456 1375s [test_voicemail_api.c:voicemail_api_off_nominal_move:1075]: Test move attempt for invalid context test_vm_api_defunct 1375s [test_voicemail_api.c:voicemail_api_off_nominal_move:1078]: Test move attempt to invalid folder 1375s [test_voicemail_api.c:voicemail_api_off_nominal_move:1081]: Test move attempt from invalid folder 1375s [test_voicemail_api.c:voicemail_api_off_nominal_move:1084]: Test move attempt to NULL folder 1375s [test_voicemail_api.c:voicemail_api_off_nominal_move:1087]: Test move attempt from NULL folder 1375s [test_voicemail_api.c:voicemail_api_off_nominal_move:1090]: Test move attempt with non-existent message number 1375s [test_voicemail_api.c:voicemail_api_off_nominal_move:1094]: Test move attempt with invalid message number 1375s [test_voicemail_api.c:voicemail_api_off_nominal_move:1098]: Test move attempt with 0 number of messages 1375s [test_voicemail_api.c:voicemail_api_off_nominal_move:1102]: Test move attempt with invalid number of messages 1375s [test_voicemail_api.c:voicemail_api_off_nominal_move:1105]: Test move attempt with non-existent multiple messages, where some messages exist 1375s END /main/voicemail_api/ - off_nominal_move Time: 9ms Result: PASS 1375s START /main/voicemail_api/ - nominal_move 1375s [test_voicemail_api.c:voicemail_api_nominal_move:987]: Created message in test_vm_api_1234/Old with ID 1712613123-909401725 1375s [test_voicemail_api.c:voicemail_api_nominal_move:987]: Created message in test_vm_api_1234/INBOX with ID 1712613123-960311778 1375s [test_voicemail_api.c:voicemail_api_nominal_move:987]: Created message in test_vm_api_2345/INBOX with ID 1712613123-1500739833 1375s [test_voicemail_api.c:voicemail_api_nominal_move:987]: Created message in test_vm_api_2345/INBOX with ID 1712613123-719848782 1375s [test_voicemail_api.c:voicemail_api_nominal_move:994]: Test move of test_vm_api_1234 message from INBOX to Family 1375s [test_voicemail_api.c:voicemail_api_nominal_move:997]: Test move of test_vm_api_1234 message from Old to Family 1375s [test_voicemail_api.c:voicemail_api_nominal_move:1011]: Test move of test_vm_api_2345 messages from Inbox to Family 1375s [test_voicemail_api.c:voicemail_api_nominal_move:1022]: Test move of test_vm_api_2345 message from Family to INBOX 1375s END /main/voicemail_api/ - nominal_move Time: 15ms Result: PASS 1375s START /main/voicemail_api/ - off_nominal_snapshot 1375s [test_voicemail_api.c:voicemail_api_off_nominal_snapshot:947]: Created message in test_vm_api_1234/Old with ID 1712613123-909401725 1375s [test_voicemail_api.c:voicemail_api_off_nominal_snapshot:947]: Created message in test_vm_api_1234/INBOX with ID 1712613123-960311778 1375s [test_voicemail_api.c:voicemail_api_off_nominal_snapshot:947]: Created message in test_vm_api_2345/INBOX with ID 1712613123-1500739833 1375s [test_voicemail_api.c:voicemail_api_off_nominal_snapshot:947]: Created message in test_vm_api_2345/INBOX with ID 1712613123-719848782 1375s [test_voicemail_api.c:voicemail_api_off_nominal_snapshot:949]: Test access to non-existent mailbox test_vm_api_3456 1375s [test_voicemail_api.c:voicemail_api_off_nominal_snapshot:952]: Test access to null mailbox 1375s [test_voicemail_api.c:voicemail_api_off_nominal_snapshot:955]: Test access non-existent context test_vm_api_defunct 1375s [test_voicemail_api.c:voicemail_api_off_nominal_snapshot:958]: Test non-existent folder test_vm_api_platypus 1375s END /main/voicemail_api/ - off_nominal_snapshot Time: 8ms Result: PASS 1375s START /main/voicemail_api/ - nominal_snapshot 1375s [test_voicemail_api.c:voicemail_api_nominal_snapshot:856]: Created message in test_vm_api_1234/Old with ID 1712613123-909401725 1375s [test_voicemail_api.c:voicemail_api_nominal_snapshot:856]: Created message in test_vm_api_1234/INBOX with ID 1712613123-960311778 1375s [test_voicemail_api.c:voicemail_api_nominal_snapshot:856]: Created message in test_vm_api_2345/INBOX with ID 1712613123-1500739833 1375s [test_voicemail_api.c:voicemail_api_nominal_snapshot:856]: Created message in test_vm_api_2345/INBOX with ID 1712613123-719848782 1375s [test_voicemail_api.c:voicemail_api_nominal_snapshot:858]: Test retrieving message 1 from INBOX of test_vm_1234 1375s [test_voicemail_api.c:voicemail_api_nominal_snapshot:861]: Found message 1712613123-960311778 in snapshot 1375s [test_voicemail_api.c:voicemail_api_nominal_snapshot:864]: Test retrieving message 0 from Old of test_vm_1234 1375s [test_voicemail_api.c:voicemail_api_nominal_snapshot:867]: Found message 1712613123-909401725 in snapshot 1375s [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 1375s [test_voicemail_api.c:voicemail_api_nominal_snapshot:873]: Found message 1712613123-909401725 in snapshot 1375s [test_voicemail_api.c:voicemail_api_nominal_snapshot:874]: Found message 1712613123-960311778 in snapshot 1375s [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 1375s [test_voicemail_api.c:voicemail_api_nominal_snapshot:880]: Found message 1712613123-960311778 in snapshot 1375s [test_voicemail_api.c:voicemail_api_nominal_snapshot:881]: Found message 1712613123-909401725 in snapshot 1375s [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 1375s [test_voicemail_api.c:voicemail_api_nominal_snapshot:887]: Found message 1712613123-960311778 in snapshot 1375s [test_voicemail_api.c:voicemail_api_nominal_snapshot:888]: Found message 1712613123-909401725 in snapshot 1375s [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 1375s [test_voicemail_api.c:voicemail_api_nominal_snapshot:894]: Found message 1712613123-909401725 in snapshot 1375s [test_voicemail_api.c:voicemail_api_nominal_snapshot:895]: Found message 1712613123-960311778 in snapshot 1375s [test_voicemail_api.c:voicemail_api_nominal_snapshot:898]: Test retrieving message 0, 1 from all folders of test_vm_1234 ordered by id 1375s [test_voicemail_api.c:voicemail_api_nominal_snapshot:901]: Found message 1712613123-909401725 in snapshot 1375s [test_voicemail_api.c:voicemail_api_nominal_snapshot:902]: Found message 1712613123-960311778 in snapshot 1375s [test_voicemail_api.c:voicemail_api_nominal_snapshot:905]: Test retrieving message 0, 1 from all folders of test_vm_1234 ordered by time 1375s [test_voicemail_api.c:voicemail_api_nominal_snapshot:908]: Found message 1712613123-909401725 in snapshot 1375s [test_voicemail_api.c:voicemail_api_nominal_snapshot:909]: Found message 1712613123-960311778 in snapshot 1375s [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 1375s [test_voicemail_api.c:voicemail_api_nominal_snapshot:915]: Found message 1712613123-909401725 in snapshot 1375s [test_voicemail_api.c:voicemail_api_nominal_snapshot:916]: Found message 1712613123-960311778 in snapshot 1375s END /main/voicemail_api/ - nominal_snapshot Time: 20ms Result: PASS 1375s START /main/xml_escape/ - xml_escape_test 1375s END /main/xml_escape/ - xml_escape_test Time: <1ms Result: PASS 1375s START /mwi/ - explicit_publish 1375s END /mwi/ - explicit_publish Time: 40ms Result: PASS 1375s START /mwi/ - implicit_publish 1375s END /mwi/ - implicit_publish Time: 29ms Result: PASS 1375s START /res/adsi/ - adsi_loaded_test 1375s END /res/adsi/ - adsi_loaded_test Time: <1ms Result: PASS 1375s START /res/aeap/ - send_msg_handle_request 1375s END /res/aeap/ - send_msg_handle_request Time: <1ms Result: PASS 1375s START /res/aeap/ - send_msg_handle_response 1375s END /res/aeap/ - send_msg_handle_response Time: <1ms Result: PASS 1375s START /res/aeap/ - send_msg_handle_string 1377s END /res/aeap/ - send_msg_handle_string Time: 1999ms Result: PASS 1377s START /res/aeap/ - create_and_connect 1377s END /res/aeap/ - create_and_connect Time: <1ms Result: PASS 1377s START /res/aeap/speech/ - res_speech_aeap_test 1377s END /res/aeap/speech/ - res_speech_aeap_test Time: 1ms Result: PASS 1377s START /res/aeap/transaction/ - transaction_exec_timeout 1377s END /res/aeap/transaction/ - transaction_exec_timeout Time: 99ms Result: PASS 1377s START /res/aeap/transaction/ - transaction_exec 1378s END /res/aeap/transaction/ - transaction_exec Time: 1000ms Result: PASS 1378s START /res/aeap/transport/ - transport_create_invalid 1378s END /res/aeap/transport/ - transport_create_invalid Time: <1ms Result: PASS 1378s START /res/aeap/transport/ - transport_create 1378s END /res/aeap/transport/ - transport_create Time: <1ms Result: PASS 1378s START /res/aeap/transport/ - transport_connect 1378s END /res/aeap/transport/ - transport_connect Time: <1ms Result: PASS 1378s START /res/aeap/transport/ - transport_connect_fail 1378s END /res/aeap/transport/ - transport_connect_fail Time: <1ms Result: PASS 1378s START /res/aeap/transport/ - transport_binary 1378s END /res/aeap/transport/ - transport_binary Time: <1ms Result: PASS 1378s START /res/aeap/transport/ - transport_string 1378s END /res/aeap/transport/ - transport_string Time: <1ms Result: PASS 1378s START /res/agi/ - agi_loaded_test 1378s END /res/agi/ - agi_loaded_test Time: <1ms Result: PASS 1378s START /res/agi/ - null_agi_docs 1378s END /res/agi/ - null_agi_docs Time: <1ms Result: PASS 1378s START /res/ari/ - invoke_not_found 1378s END /res/ari/ - invoke_not_found Time: <1ms Result: PASS 1378s START /res/ari/ - invoke_bad_post 1378s END /res/ari/ - invoke_bad_post Time: <1ms Result: PASS 1378s START /res/ari/ - invoke_post 1378s END /res/ari/ - invoke_post Time: <1ms Result: PASS 1378s START /res/ari/ - invoke_delete 1378s END /res/ari/ - invoke_delete Time: <1ms Result: PASS 1378s START /res/ari/ - invoke_wildcard 1378s END /res/ari/ - invoke_wildcard Time: <1ms Result: PASS 1378s START /res/ari/ - invoke_get 1378s END /res/ari/ - invoke_get Time: <1ms Result: PASS 1378s START /res/ari/ - get_docs_hackerz 1378s END /res/ari/ - get_docs_hackerz Time: <1ms Result: PASS 1378s START /res/ari/ - get_docs_notfound 1378s END /res/ari/ - get_docs_notfound Time: <1ms Result: PASS 1378s START /res/ari/ - get_docs_nohost 1378s END /res/ari/ - get_docs_nohost Time: <1ms Result: PASS 1378s START /res/ari/ - get_docs 1378s END /res/ari/ - get_docs Time: <1ms Result: PASS 1378s START /res/crypto/ - crypto_loaded_test 1378s END /res/crypto/ - crypto_loaded_test Time: <1ms Result: PASS 1378s START /res/http_media_cache/ - retrieve_content_type 1378s [test_http_media_cache.c:retrieve_content_type:255]: Condition failed: bucket_file != NULL 1378s END /res/http_media_cache/ - retrieve_content_type Time: <1ms Result: FAIL 1378s START /res/http_media_cache/ - retrieve_parsed_uri 1378s [test_http_media_cache.c:retrieve_parsed_uri:289]: Condition failed: bucket_file != NULL 1378s END /res/http_media_cache/ - retrieve_parsed_uri Time: <1ms Result: FAIL 1378s START /res/http_media_cache/ - retrieve_cache_control_directives 1378s [test_http_media_cache.c:retrieve_cache_control_directives:322]: Testing no-cache... 1378s [test_http_media_cache.c:retrieve_cache_control_directives:325]: Condition failed: bucket_file != NULL 1378s END /res/http_media_cache/ - retrieve_cache_control_directives Time: <1ms Result: FAIL 1378s START /res/http_media_cache/ - retrieve_cache_control_age 1378s [test_http_media_cache.c:retrieve_cache_control_age:406]: Testing max-age... 1378s [test_http_media_cache.c:retrieve_cache_control_age:409]: Condition failed: bucket_file != NULL 1378s END /res/http_media_cache/ - retrieve_cache_control_age Time: <1ms Result: FAIL 1378s START /res/http_media_cache/ - retrieve_etag_expired 1378s [test_http_media_cache.c:retrieve_etag_expired:510]: Condition failed: bucket_file != NULL 1378s END /res/http_media_cache/ - retrieve_etag_expired Time: <1ms Result: FAIL 1378s START /res/http_media_cache/ - retrieve_expires 1378s [test_http_media_cache.c:retrieve_expires:551]: Condition failed: bucket_file != NULL 1378s END /res/http_media_cache/ - retrieve_expires Time: <1ms Result: FAIL 1378s START /res/http_media_cache/ - retrieve_etag 1378s [test_http_media_cache.c:retrieve_etag:600]: Condition failed: bucket_file != NULL 1378s END /res/http_media_cache/ - retrieve_etag Time: <1ms Result: FAIL 1378s START /res/http_media_cache/ - retrieve_nominal 1378s [test_http_media_cache.c:retrieve_nominal:639]: Condition failed: bucket_file != NULL 1378s END /res/http_media_cache/ - retrieve_nominal Time: <1ms Result: FAIL 1378s START /res/http_media_cache/ - create_nominal 1378s [test_http_media_cache.c:create_nominal:673]: Condition failed: ast_bucket_file_temporary_create(bucket_file) == 0 1378s END /res/http_media_cache/ - create_nominal Time: <1ms Result: FAIL 1378s START /res/parking/ - dynamic_parking_variables 1378s [parking/parking_tests.c:dynamic_parking_variables:756]: Creating expected configuration for dynamic parking lot 1378s [parking/parking_tests.c:dynamic_parking_variables:775]: Creating template lot 1378s [parking/parking_tests.c:dynamic_parking_variables:784]: Creating Alice channel to test dynamic parking lot creation. 1378s [parking/parking_tests.c:dynamic_parking_variables:794]: Setting Dynamic Parking channel variables on Alice. 1378s [parking/parking_tests.c:dynamic_parking_variables:802]: Generating dynamic parking lot based on Alice's channel variables. 1378s [parking/parking_tests.c:dynamic_parking_variables:819]: Dynamic parking lot created successfully and matches expectations. Test passed. 1378s END /res/parking/ - dynamic_parking_variables Time: <1ms Result: PASS 1378s START /res/parking/ - extension_conflicts 1378s [parking/parking_tests.c:extension_conflicts:597]: Creating the base lot. This should pass. 1378s [parking/parking_tests.c:extension_conflicts:607]: Creating a test lot which will overlap. 1378s [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. 1378s [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. 1378s [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. 1378s [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. 1378s END /res/parking/ - extension_conflicts Time: <1ms Result: PASS 1378s START /res/parking/ - park_extensions 1378s [parking/parking_tests.c:park_extensions:551]: Extensions for the test parking lot were verified. Cleaning up and verifying their removal. 1378s [parking/parking_tests.c:park_extensions:565]: Extensions for the test parking lot verified as removed. Test completed successfully. 1378s END /res/parking/ - park_extensions Time: <1ms Result: PASS 1378s START /res/parking/ - park_retrieve 1378s [parking/parking_tests.c:retrieve_call:405]: Creating test parking lot 'unit_tests_res_parking_test_lot' 1379s [parking/parking_tests.c:retrieve_call:446]: Successfully retrieved parked user from the parking lot. Validating user data. 1379s END /res/parking/ - park_retrieve Time: 1000ms Result: PASS 1379s START /res/parking/ - park_channel 1379s [parking/parking_tests.c:park_call:254]: Creating test parking lot 'unit_tests_res_parking_test_lot' 1380s END /res/parking/ - park_channel Time: 1000ms Result: PASS 1380s START /res/parking/ - create_lot 1380s [parking/parking_tests.c:create_lot:206]: Creating test parking lot 'unit_tests_res_parking_test_lot' 1380s [parking/parking_tests.c:create_lot:214]: Successfully created parking lot. Retrieving test parking lot from container. 1380s [parking/parking_tests.c:create_lot:223]: Successfully retrieved parking lot. Removing test parking lot from container. 1380s [parking/parking_tests.c:create_lot:229]: Parking lot was successfully removed from the container. Test complete. 1380s END /res/parking/ - create_lot Time: <1ms Result: PASS 1380s START /res/prometheus/ - bridge_to_string 1380s [test_res_prometheus.c:bridge_to_string:744]: -> Retrieved: # HELP asterisk_channels_count Current channel count. 1380s # TYPE asterisk_channels_count gauge 1380s asterisk_channels_count{eid="fa:16:3e:8a:03:0b"} 0 1380s # HELP asterisk_calls_sum Total call count. 1380s # TYPE asterisk_calls_sum counter 1380s asterisk_calls_sum{eid="fa:16:3e:8a:03:0b"} 0 1380s # HELP asterisk_calls_count Current call count. 1380s # TYPE asterisk_calls_count gauge 1380s asterisk_calls_count{eid="fa:16:3e:8a:03:0b"} 0 1380s # HELP asterisk_endpoints_count Current endpoint count. 1380s # TYPE asterisk_endpoints_count gauge 1380s asterisk_endpoints_count{eid="fa:16:3e:8a:03:0b"} 0 1380s # HELP asterisk_bridges_count Current bridge count. 1380s # TYPE asterisk_bridges_count gauge 1380s asterisk_bridges_count{eid="fa:16:3e:8a:03:0b"} 2 1380s # HELP asterisk_bridges_channels_count Number of channels in the bridge. 1380s # TYPE asterisk_bridges_channels_count gauge 1380s asterisk_bridges_channels_count{eid="fa:16:3e:8a:03:0b",id="2a70f4ee-4d77-4a4c-ad22-760a20f82f46",tech="simple_bridge",subclass="basic",creator="",name=""} 0 1380s 1380s END /res/prometheus/ - bridge_to_string Time: <1ms Result: PASS 1380s START /res/prometheus/ - config_general_core_metrics 1380s [test_res_prometheus.c:config_general_core_metrics:680]: -> CURLing request... 1380s [test_res_prometheus.c:config_general_core_metrics:688]: -> Retrieved: # HELP asterisk_channels_count Current channel count. 1380s # TYPE asterisk_channels_count gauge 1380s asterisk_channels_count{eid="fa:16:3e:8a:03:0b"} 0 1380s # HELP asterisk_calls_sum Total call count. 1380s # TYPE asterisk_calls_sum counter 1380s asterisk_calls_sum{eid="fa:16:3e:8a:03:0b"} 0 1380s # HELP asterisk_calls_count Current call count. 1380s # TYPE asterisk_calls_count gauge 1380s asterisk_calls_count{eid="fa:16:3e:8a:03:0b"} 0 1380s # HELP asterisk_endpoints_count Current endpoint count. 1380s # TYPE asterisk_endpoints_count gauge 1380s asterisk_endpoints_count{eid="fa:16:3e:8a:03:0b"} 0 1380s # HELP asterisk_bridges_count Current bridge count. 1380s # TYPE asterisk_bridges_count gauge 1380s asterisk_bridges_count{eid="fa:16:3e:8a:03:0b"} 0 1380s # HELP asterisk_core_properties Asterisk instance properties. The value of this will always be 1. 1380s # TYPE asterisk_core_properties counter 1380s asterisk_core_properties{eid="fa:16:3e:8a:03:0b",version="20.6.0~dfsg+~cs6.13.40431414-2build4",build_options="OPTIONAL_API, TEST_FRAMEWORK",build_date="2024-03-31 00:19:29 UTC",build_os="Linux",build_kernel="unknown",build_host="buildd.debian.org"} 1 1380s # HELP asterisk_core_uptime_seconds Asterisk instance uptime in seconds. 1380s # TYPE asterisk_core_uptime_seconds counter 1380s asterisk_core_uptime_seconds{eid="fa:16:3e:8a:03:0b"} 172 1380s # HELP asterisk_core_last_reload_seconds Time since last Asterisk reload in seconds. 1380s # TYPE asterisk_core_last_reload_seconds counter 1380s asterisk_core_last_reload_seconds{eid="fa:16:3e:8a:03:0b"} 172 1380s # HELP asterisk_core_scrape_time_ms Total time taken to collect metrics, in milliseconds 1380s # TYPE asterisk_core_scrape_time_ms counter 1380s asterisk_core_scrape_time_ms{eid="fa:16:3e:8a:03:0b"} 0 1380s 1380s [test_res_prometheus.c:config_general_core_metrics:690]: -> Checking for core properties 1380s [test_res_prometheus.c:config_general_core_metrics:693]: -> Checking for uptime 1380s [test_res_prometheus.c:config_general_core_metrics:696]: -> Checking for last reload 1380s [test_res_prometheus.c:config_general_core_metrics:699]: -> Checking for scrape time 1380s END /res/prometheus/ - config_general_core_metrics Time: 1ms Result: PASS 1380s START /res/prometheus/ - config_general_basic_auth 1380s [test_res_prometheus.c:config_general_basic_auth:555]: Testing without auth credentials 1380s [test_res_prometheus.c:config_general_basic_auth:556]: -> CURLing request... 1380s [test_res_prometheus.c:config_general_basic_auth:563]: -> CURL returned 401 1380s [test_res_prometheus.c:config_general_basic_auth:566]: Testing with invalid auth credentials 1380s [test_res_prometheus.c:config_general_basic_auth:567]: -> CURLing request... 1380s [test_res_prometheus.c:config_general_basic_auth:576]: -> CURL returned 401 1380s [test_res_prometheus.c:config_general_basic_auth:579]: Testing with valid auth credentials 1380s [test_res_prometheus.c:config_general_basic_auth:580]: -> CURLing request... 1380s [test_res_prometheus.c:config_general_basic_auth:588]: -> CURL returned 200 1380s END /res/prometheus/ - config_general_basic_auth Time: <1ms Result: PASS 1380s START /res/prometheus/ - config_general_enabled 1380s [test_res_prometheus.c:config_general_enabled:628]: -> CURLing request... 1380s [test_res_prometheus.c:config_general_enabled:635]: -> CURL returned 503 1380s END /res/prometheus/ - config_general_enabled Time: <1ms Result: PASS 1380s START /res/prometheus/ - gauge_create 1380s END /res/prometheus/ - gauge_create Time: <1ms Result: PASS 1380s START /res/prometheus/ - gauge_to_string 1380s END /res/prometheus/ - gauge_to_string Time: <1ms Result: PASS 1380s START /res/prometheus/ - counter_create 1380s END /res/prometheus/ - counter_create Time: <1ms Result: PASS 1380s START /res/prometheus/ - counter_to_string 1380s END /res/prometheus/ - counter_to_string Time: <1ms Result: PASS 1380s START /res/prometheus/ - metric_register 1380s [test_res_prometheus.c:metric_register:291]: Testing nominal registration 1380s [test_res_prometheus.c:metric_register:292]: -> Static metric 1380s [test_res_prometheus.c:metric_register:294]: -> Malloc'd metric 1380s [test_res_prometheus.c:metric_register:300]: Testing nominal registration of child metrics 1380s [test_res_prometheus.c:metric_register:315]: Testing name collisions 1380s [test_res_prometheus.c:metric_register:322]: Testing label collisions 1380s [test_res_prometheus.c:metric_register:331]: Testing removal of metrics 1380s END /res/prometheus/ - metric_register Time: <1ms Result: PASS 1380s START /res/prometheus/ - metric_callback_register 1380s [test_res_prometheus.c:metric_callback_register:241]: -> CURLing request... 1380s [test_res_prometheus.c:metric_callback_register:250]: -> Retrieved: # HELP asterisk_channels_count Current channel count. 1380s # TYPE asterisk_channels_count gauge 1380s asterisk_channels_count{eid="fa:16:3e:8a:03:0b"} 0 1380s # HELP asterisk_calls_sum Total call count. 1380s # TYPE asterisk_calls_sum counter 1380s asterisk_calls_sum{eid="fa:16:3e:8a:03:0b"} 0 1380s # HELP asterisk_calls_count Current call count. 1380s # TYPE asterisk_calls_count gauge 1380s asterisk_calls_count{eid="fa:16:3e:8a:03:0b"} 0 1380s # HELP asterisk_endpoints_count Current endpoint count. 1380s # TYPE asterisk_endpoints_count gauge 1380s asterisk_endpoints_count{eid="fa:16:3e:8a:03:0b"} 0 1380s # HELP asterisk_bridges_count Current bridge count. 1380s # TYPE asterisk_bridges_count gauge 1380s asterisk_bridges_count{eid="fa:16:3e:8a:03:0b"} 0 1380s # HELP test_counter A test counter 1380s # TYPE test_counter counter 1380s test_counter 0 1380s 1380s END /res/prometheus/ - metric_callback_register Time: <1ms Result: PASS 1380s START /res/prometheus/ - metric_values 1380s [test_res_prometheus.c:metric_values:166]: -> CURLing request... 1380s [test_res_prometheus.c:metric_values:176]: -> Retrieved: # HELP asterisk_channels_count Current channel count. 1380s # TYPE asterisk_channels_count gauge 1380s asterisk_channels_count{eid="fa:16:3e:8a:03:0b"} 0 1380s # HELP asterisk_calls_sum Total call count. 1380s # TYPE asterisk_calls_sum counter 1380s asterisk_calls_sum{eid="fa:16:3e:8a:03:0b"} 0 1380s # HELP asterisk_calls_count Current call count. 1380s # TYPE asterisk_calls_count gauge 1380s asterisk_calls_count{eid="fa:16:3e:8a:03:0b"} 0 1380s # HELP asterisk_endpoints_count Current endpoint count. 1380s # TYPE asterisk_endpoints_count gauge 1380s asterisk_endpoints_count{eid="fa:16:3e:8a:03:0b"} 0 1380s # HELP asterisk_bridges_count Current bridge count. 1380s # TYPE asterisk_bridges_count gauge 1380s asterisk_bridges_count{eid="fa:16:3e:8a:03:0b"} 0 1380s # HELP test_counter_one A test counter 1380s # TYPE test_counter_one counter 1380s test_counter_one 1 1380s # HELP test_counter_two A test counter 1380s # TYPE test_counter_two counter 1380s test_counter_two 2 1380s 1380s END /res/prometheus/ - metric_values Time: <1ms Result: PASS 1380s START /res/res_crypto/ - crypto_aes_decrypt 1380s [test_crypto.c:crypto_aes_decrypt:607]: Executing AES-ECB decryption test 1380s END /res/res_crypto/ - crypto_aes_decrypt Time: 21ms Result: PASS 1380s START /res/res_crypto/ - crypto_aes_encrypt 1380s [test_crypto.c:crypto_aes_encrypt:531]: Executing AES-ECB encryption test 1380s END /res/res_crypto/ - crypto_aes_encrypt Time: 17ms Result: PASS 1380s START /res/res_crypto/ - crypto_verify 1380s [test_crypto.c:crypto_verify:425]: Executing RSA signature verification test 1380s [test_crypto.c:crypto_verify:456]: Couldn't read key: rsa_key1 1380s END /res/res_crypto/ - crypto_verify Time: <1ms Result: FAIL 1380s START /res/res_crypto/ - crypto_sign 1380s [test_crypto.c:crypto_sign:306]: Executing RSA signing test 1380s [test_crypto.c:crypto_sign:341]: Couldn't read key: rsa_key1 1380s END /res/res_crypto/ - crypto_sign Time: <1ms Result: FAIL 1380s START /res/res_crypto/ - crypto_decrypt_pub_key 1380s [test_crypto.c:crypto_rsa_decrypt:203]: Executing RSA decryption test 1380s [test_crypto.c:crypto_rsa_decrypt:231]: Couldn't read key: rsa_key1 1380s END /res/res_crypto/ - crypto_decrypt_pub_key Time: <1ms Result: FAIL 1380s START /res/res_crypto/ - crypto_rsa_encrypt 1380s [test_crypto.c:crypto_rsa_encrypt:107]: Executing RSA encryption test 1380s [test_crypto.c:crypto_rsa_encrypt:138]: Couldn't read key: rsa_key1 1380s END /res/res_crypto/ - crypto_rsa_encrypt Time: <1ms Result: FAIL 1380s START /res/res_pjproject/ - ast_sockaddr_from_pj_sockaddr_test 1380s END /res/res_pjproject/ - ast_sockaddr_from_pj_sockaddr_test Time: <1ms Result: PASS 1380s START /res/res_pjproject/ - ast_sockaddr_to_pj_sockaddr_test 1380s END /res/res_pjproject/ - ast_sockaddr_to_pj_sockaddr_test Time: <1ms Result: PASS 1380s START /res/res_pjsip/ - xml_sanitization_exceeds_buffer 1380s END /res/res_pjsip/ - xml_sanitization_exceeds_buffer Time: <1ms Result: PASS 1380s START /res/res_pjsip/ - xml_sanitization_end_null 1380s END /res/res_pjsip/ - xml_sanitization_end_null Time: <1ms Result: PASS 1380s START /res/res_pjsip/scheduler/ - scheduler_policy 1380s [test_res_pjsip_scheduler.c:scheduler_policy:355]: This test will take about 4.5 seconds 1384s END /res/res_pjsip/scheduler/ - scheduler_policy Time: 4499ms Result: PASS 1385s START /res/res_pjsip/scheduler/ - scheduler_cancel 1385s [test_res_pjsip_scheduler.c:scheduler_cancel:301]: This test will take about 1.5 seconds 1386s END /res/res_pjsip/scheduler/ - scheduler_cancel Time: 1500ms Result: PASS 1386s START /res/res_pjsip/scheduler/ - scheduler_cleanup 1386s [test_res_pjsip_scheduler.c:scheduler_cleanup:250]: This test will take about 1.6 seconds 1388s END /res/res_pjsip/scheduler/ - scheduler_cleanup Time: 1600ms Result: PASS 1388s START /res/res_pjsip/scheduler/ - unserialized_scheduler 1388s [test_res_pjsip_scheduler.c:scheduler:136]: This test will take about 3.0 seconds 1391s END /res/res_pjsip/scheduler/ - unserialized_scheduler Time: 2999ms Result: PASS 1391s START /res/res_pjsip/scheduler/ - serialized_scheduler 1391s [test_res_pjsip_scheduler.c:scheduler:131]: This test will take about 4.0 seconds 1395s END /res/res_pjsip/scheduler/ - serialized_scheduler Time: 3999ms Result: PASS 1395s START /res/res_pjsip_pubsub/ - bad_event 1395s END /res/res_pjsip_pubsub/ - bad_event Time: <1ms Result: PASS 1395s START /res/res_pjsip_pubsub/ - loop 1395s END /res/res_pjsip_pubsub/ - loop Time: <1ms Result: PASS 1395s START /res/res_pjsip_pubsub/ - duplicate_resource 1395s END /res/res_pjsip_pubsub/ - duplicate_resource Time: <1ms Result: PASS 1395s START /res/res_pjsip_pubsub/ - bad_branch 1395s END /res/res_pjsip_pubsub/ - bad_branch Time: <1ms Result: PASS 1395s START /res/res_pjsip_pubsub/ - bad_resource 1395s END /res/res_pjsip_pubsub/ - bad_resource Time: <1ms Result: PASS 1395s START /res/res_pjsip_pubsub/ - complex_resource_tree 1395s END /res/res_pjsip_pubsub/ - complex_resource_tree Time: <1ms Result: PASS 1395s START /res/res_pjsip_pubsub/ - resource_tree 1395s END /res/res_pjsip_pubsub/ - resource_tree Time: <1ms Result: PASS 1395s START /res/res_pjsip_session/ - merge_refresh_topologies 1395s [res_pjsip_session.c:test_resolve_refresh_media_states:5894]: Test 1 passed 1395s [res_pjsip_session.c:test_resolve_refresh_media_states:5914]: Test 2 passed 1395s [res_pjsip_session.c:test_resolve_refresh_media_states:5938]: Test 3 passed 1395s [res_pjsip_session.c:test_resolve_refresh_media_states:5957]: Test 4 passed 1395s [res_pjsip_session.c:test_resolve_refresh_media_states:5975]: Test 5 passed 1395s [res_pjsip_session.c:test_resolve_refresh_media_states:5996]: Test 6 passed 1395s [res_pjsip_session.c:test_resolve_refresh_media_states:6022]: Test 7 passed 1395s [res_pjsip_session.c:test_resolve_refresh_media_states:6043]: Test 8 passed 1395s [res_pjsip_session.c:test_resolve_refresh_media_states:6063]: Test 9 passed 1395s [res_pjsip_session.c:test_resolve_refresh_media_states:6083]: Test 10 passed 1395s [res_pjsip_session.c:test_resolve_refresh_media_states:6106]: Test 11 passed 1395s [res_pjsip_session.c:test_resolve_refresh_media_states:6131]: Test 12 passed 1395s [res_pjsip_session.c:test_resolve_refresh_media_states:6165]: Test 13 passed 1395s [res_pjsip_session.c:test_resolve_refresh_media_states:6189]: Test 14 passed 1395s [res_pjsip_session.c:test_resolve_refresh_media_states:6213]: Test 15 passed 1395s END /res/res_pjsip_session/ - merge_refresh_topologies Time: <1ms Result: PASS 1395s START /res/res_pjsip_session/caps/ - low_level 1395s [test_res_pjsip_session_caps.c:low_level:134]: Testing incoming expected pass 1395s [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) 1395s [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) 1395s [test_res_pjsip_session_caps.c:test_create_joint:60]: Testing local: (slin), remote: (all), pref: (local ), outgoing: (no ), expected: (slin) expected result: (PASS) 1395s [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) 1395s [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) 1395s [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) 1395s [test_res_pjsip_session_caps.c:low_level:142]: Testing incoming expected fail 1395s [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) 1395s [test_res_pjsip_session_caps.c:test_create_joint:102]: Expected Failure: Expected: () Actual: (nothing) 1395s [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) 1395s [test_res_pjsip_session_caps.c:test_create_joint:81]: Expected Failure: Invalid preference string incoming/outgoing combination. 1395s [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) 1395s [test_res_pjsip_session_caps.c:test_create_joint:81]: Expected Failure: Invalid preference string incoming/outgoing combination. 1395s [test_res_pjsip_session_caps.c:low_level:147]: Testing outgoing expected pass 1395s [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) 1395s [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) 1395s [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) 1395s [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) 1395s [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) 1395s [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) 1395s [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) 1395s END /res/res_pjsip_session/caps/ - low_level Time: <1ms Result: PASS 1395s START /res/res_resolver_unbound/ - resolve_srv 1395s END /res/res_resolver_unbound/ - resolve_srv Time: 2ms Result: PASS 1395s START /res/res_resolver_unbound/ - resolve_naptr 1395s END /res/res_resolver_unbound/ - resolve_naptr Time: <1ms Result: PASS 1395s START /res/res_resolver_unbound/ - resolve_cancel_off_nominal 1395s END /res/res_resolver_unbound/ - resolve_cancel_off_nominal Time: 6ms Result: PASS 1395s START /res/res_resolver_unbound/ - resolve_async_off_nominal 1395s [res_resolver_unbound.c:off_nominal_async_run:995]: Performing DNS query 'duck.feathers', type 1 1395s [res_resolver_unbound.c:off_nominal_async_run:995]: Performing DNS query 'goose.feathers', type 28 1395s [res_resolver_unbound.c:off_nominal_async_run:995]: Performing DNS query 'goose.feathers', type 1 1395s END /res/res_resolver_unbound/ - resolve_async_off_nominal Time: <1ms Result: PASS 1395s START /res/res_resolver_unbound/ - resolve_sync_off_nominal 1395s END /res/res_resolver_unbound/ - resolve_sync_off_nominal Time: <1ms Result: PASS 1395s START /res/res_resolver_unbound/ - resolve_async 1395s [res_resolver_unbound.c:nominal_async_run:713]: Performing DNS query 'goose.feathers', type 1 1395s [res_resolver_unbound.c:nominal_async_run:713]: Performing DNS query 'goose.feathers', type 28 1395s [res_resolver_unbound.c:nominal_async_run:713]: Performing DNS query 'duck.feathers', type 1 1395s END /res/res_resolver_unbound/ - resolve_async Time: <1ms Result: PASS 1395s START /res/res_resolver_unbound/ - resolve_sync 1395s [res_resolver_unbound.c:nominal_sync_run:563]: Performing DNS query 'goose.feathers', type 1 1395s [res_resolver_unbound.c:nominal_sync_run:563]: Performing DNS query 'goose.feathers', type 28 1395s [res_resolver_unbound.c:nominal_sync_run:563]: Performing DNS query 'duck.feathers', type 1 1395s END /res/res_resolver_unbound/ - resolve_sync Time: <1ms Result: PASS 1395s START /res/res_rtp/ - fir_nominal 1395s END /res/res_rtp/ - fir_nominal Time: <1ms Result: PASS 1395s START /res/res_rtp/ - sr_rr_nominal 1395s END /res/res_rtp/ - sr_rr_nominal Time: <1ms Result: PASS 1395s START /res/res_rtp/ - remb_nominal 1395s END /res/res_rtp/ - remb_nominal Time: <1ms Result: PASS 1395s START /res/res_rtp/ - lost_packet_stats_nominal 1395s END /res/res_rtp/ - lost_packet_stats_nominal Time: <1ms Result: PASS 1395s START /res/res_rtp/ - nack_overflow 1395s END /res/res_rtp/ - nack_overflow Time: 1ms Result: PASS 1395s START /res/res_rtp/ - nack_nominal 1395s END /res/res_rtp/ - nack_nominal Time: 1ms Result: PASS 1395s START /res/res_rtp/ - nack_no_packet_loss 1395s END /res/res_rtp/ - nack_no_packet_loss Time: <1ms Result: PASS 1395s START /res/res_sorcery_memory_cache/ - full_backend_cache_stale 1410s END /res/res_sorcery_memory_cache/ - full_backend_cache_stale Time: 15000ms Result: PASS 1410s START /res/res_sorcery_memory_cache/ - full_backend_cache_expiration 1415s END /res/res_sorcery_memory_cache/ - full_backend_cache_expiration Time: 5000ms Result: PASS 1415s START /res/res_sorcery_memory_cache/ - expiration 1420s END /res/res_sorcery_memory_cache/ - expiration Time: 4999ms Result: PASS 1420s START /res/res_sorcery_memory_cache/ - maximum_objects 1420s END /res/res_sorcery_memory_cache/ - maximum_objects Time: 4ms Result: PASS 1420s START /res/res_sorcery_memory_cache/ - delete 1420s END /res/res_sorcery_memory_cache/ - delete Time: <1ms Result: PASS 1420s START /res/res_sorcery_memory_cache/ - create 1420s END /res/res_sorcery_memory_cache/ - create Time: <1ms Result: PASS 1420s START /res/res_sorcery_memory_cache/ - create 1420s END /res/res_sorcery_memory_cache/ - create Time: <1ms Result: PASS 1420s START /res/res_sorcery_memory_cache/ - open_with_invalid_options 1420s END /res/res_sorcery_memory_cache/ - open_with_invalid_options Time: <1ms Result: PASS 1420s START /res/res_sorcery_memory_cache/ - open_with_valid_options 1420s END /res/res_sorcery_memory_cache/ - open_with_valid_options Time: <1ms Result: PASS 1420s START /res/res_sorcery_memory_cache/ - stale 1420s [res_sorcery_memory_cache.c:stale:3189]: Begininning iteration 0 1425s [res_sorcery_memory_cache.c:stale:3189]: Begininning iteration 1 1430s [res_sorcery_memory_cache.c:stale:3189]: Begininning iteration 2 1435s END /res/res_sorcery_memory_cache/ - stale Time: 15000ms Result: PASS 1435s START /res/res_sorcery_memory_cache/thrash/ - high_object_count_without_expiration 1438s END /res/res_sorcery_memory_cache/thrash/ - high_object_count_without_expiration Time: 3028ms Result: PASS 1438s START /res/res_sorcery_memory_cache/thrash/ - conflicting_expire_and_stale 1444s END /res/res_sorcery_memory_cache/thrash/ - conflicting_expire_and_stale Time: 6015ms Result: PASS 1444s START /res/res_sorcery_memory_cache/thrash/ - unique_objects_exceeding_maximum_with_expire_and_stale 1450s END /res/res_sorcery_memory_cache/thrash/ - unique_objects_exceeding_maximum_with_expire_and_stale Time: 6007ms Result: PASS 1450s START /res/res_sorcery_memory_cache/thrash/ - unique_objects_exceeding_maximum 1453s END /res/res_sorcery_memory_cache/thrash/ - unique_objects_exceeding_maximum Time: 3006ms Result: PASS 1453s START /res/res_sorcery_memory_cache/thrash/ - low_unique_object_count_high_concurrent_updates 1456s END /res/res_sorcery_memory_cache/thrash/ - low_unique_object_count_high_concurrent_updates Time: 3002ms Result: PASS 1456s START /res/res_sorcery_memory_cache/thrash/ - low_unique_object_count_immediately_expire 1459s END /res/res_sorcery_memory_cache/thrash/ - low_unique_object_count_immediately_expire Time: 3010ms Result: PASS 1459s START /res/res_sorcery_memory_cache/thrash/ - low_unique_object_count_immediately_stale 1462s END /res/res_sorcery_memory_cache/thrash/ - low_unique_object_count_immediately_stale Time: 3009ms Result: PASS 1462s START /res/res_stir_shaken/ - stir_shaken_verify 1462s END /res/res_stir_shaken/ - stir_shaken_verify Time: 4ms Result: PASS 1462s START /res/res_stir_shaken/ - stir_shaken_sign 1462s END /res/res_stir_shaken/ - stir_shaken_sign Time: <1ms Result: PASS 1462s START /res/sorcery_astdb/ - object_delete_uncreated 1462s END /res/sorcery_astdb/ - object_delete_uncreated Time: <1ms Result: PASS 1462s START /res/sorcery_astdb/ - object_delete 1462s END /res/sorcery_astdb/ - object_delete Time: <1ms Result: PASS 1462s START /res/sorcery_astdb/ - object_update_uncreated 1462s END /res/sorcery_astdb/ - object_update_uncreated Time: <1ms Result: PASS 1462s START /res/sorcery_astdb/ - object_update 1462s END /res/sorcery_astdb/ - object_update Time: <1ms Result: PASS 1462s START /res/sorcery_astdb/ - object_retrieve_regex 1462s END /res/sorcery_astdb/ - object_retrieve_regex Time: <1ms Result: PASS 1462s START /res/sorcery_astdb/ - object_retrieve_multiple_field 1462s END /res/sorcery_astdb/ - object_retrieve_multiple_field Time: <1ms Result: PASS 1462s START /res/sorcery_astdb/ - object_retrieve_multiple_all 1462s END /res/sorcery_astdb/ - object_retrieve_multiple_all Time: <1ms Result: PASS 1462s START /res/sorcery_astdb/ - object_retrieve_field 1462s END /res/sorcery_astdb/ - object_retrieve_field Time: <1ms Result: PASS 1462s START /res/sorcery_astdb/ - object_retrieve_id 1462s END /res/sorcery_astdb/ - object_retrieve_id Time: <1ms Result: PASS 1462s START /res/sorcery_astdb/ - object_create 1462s END /res/sorcery_astdb/ - object_create Time: <1ms Result: PASS 1462s START /res/sorcery_realtime/ - object_filter 1462s END /res/sorcery_realtime/ - object_filter Time: <1ms Result: PASS 1462s START /res/sorcery_realtime/ - object_allocate_on_retrieval 1462s END /res/sorcery_realtime/ - object_allocate_on_retrieval Time: <1ms Result: PASS 1462s START /res/sorcery_realtime/ - object_delete_uncreated 1462s END /res/sorcery_realtime/ - object_delete_uncreated Time: <1ms Result: PASS 1462s START /res/sorcery_realtime/ - object_delete 1462s END /res/sorcery_realtime/ - object_delete Time: <1ms Result: PASS 1462s START /res/sorcery_realtime/ - object_update 1462s END /res/sorcery_realtime/ - object_update Time: <1ms Result: PASS 1462s START /res/sorcery_realtime/ - object_retrieve_regex_nofetch 1462s END /res/sorcery_realtime/ - object_retrieve_regex_nofetch Time: <1ms Result: PASS 1462s START /res/sorcery_realtime/ - object_retrieve_regex 1462s END /res/sorcery_realtime/ - object_retrieve_regex Time: <1ms Result: PASS 1462s START /res/sorcery_realtime/ - object_retrieve_multiple_field 1462s END /res/sorcery_realtime/ - object_retrieve_multiple_field Time: <1ms Result: PASS 1462s START /res/sorcery_realtime/ - object_retrieve_multiple_all_nofetch 1462s END /res/sorcery_realtime/ - object_retrieve_multiple_all_nofetch Time: <1ms Result: PASS 1462s START /res/sorcery_realtime/ - object_retrieve_multiple_all 1462s END /res/sorcery_realtime/ - object_retrieve_multiple_all Time: <1ms Result: PASS 1462s START /res/sorcery_realtime/ - object_retrieve_field 1462s END /res/sorcery_realtime/ - object_retrieve_field Time: <1ms Result: PASS 1462s START /res/sorcery_realtime/ - object_retrieve_id 1462s END /res/sorcery_realtime/ - object_retrieve_id Time: <1ms Result: PASS 1462s START /res/sorcery_realtime/ - object_create 1462s END /res/sorcery_realtime/ - object_create Time: <1ms Result: PASS 1462s START /res/websocket/ - websocket_client_multiple_protocols 1462s END /res/websocket/ - websocket_client_multiple_protocols Time: <1ms Result: PASS 1462s START /res/websocket/ - websocket_client_unsupported_protocol 1462s END /res/websocket/ - websocket_client_unsupported_protocol Time: <1ms Result: PASS 1462s START /res/websocket/ - websocket_client_bad_url 1462s END /res/websocket/ - websocket_client_bad_url Time: <1ms Result: PASS 1462s START /stasis/channels/ - channel_redirect_snapshot_json 1462s END /stasis/channels/ - channel_redirect_snapshot_json Time: <1ms Result: PASS 1462s START /stasis/channels/ - channel_snapshot_json 1462s END /stasis/channels/ - channel_snapshot_json Time: <1ms Result: PASS 1462s START /stasis/channels/ - multi_channel_blob_snapshots 1462s END /stasis/channels/ - multi_channel_blob_snapshots Time: <1ms Result: PASS 1462s START /stasis/channels/ - multi_channel_blob_create 1462s END /stasis/channels/ - multi_channel_blob_create Time: <1ms Result: PASS 1462s START /stasis/channels/ - null_blob 1462s END /stasis/channels/ - null_blob Time: <1ms Result: PASS 1462s START /stasis/channels/ - channel_blob_create 1462s END /stasis/channels/ - channel_blob_create Time: <1ms Result: PASS 1462s START /stasis/core/ - caching_dtor_order 1462s END /stasis/core/ - caching_dtor_order Time: <1ms Result: PASS 1462s START /stasis/core/ - dtor_order 1462s END /stasis/core/ - dtor_order Time: <1ms Result: PASS 1462s START /stasis/core/ - to_ami 1462s END /stasis/core/ - to_ami Time: <1ms Result: PASS 1462s START /stasis/core/ - no_to_ami 1462s END /stasis/core/ - no_to_ami Time: <1ms Result: PASS 1462s START /stasis/core/ - to_json 1462s END /stasis/core/ - to_json Time: <1ms Result: PASS 1462s START /stasis/core/ - no_to_json 1462s END /stasis/core/ - no_to_json Time: <1ms Result: PASS 1462s START /stasis/core/ - subscription_interleaving 1462s END /stasis/core/ - subscription_interleaving Time: <1ms Result: PASS 1462s START /stasis/core/ - interleaving 1462s END /stasis/core/ - interleaving Time: <1ms Result: PASS 1462s START /stasis/core/ - router_cache_updates 1462s END /stasis/core/ - router_cache_updates Time: 100ms Result: PASS 1462s START /stasis/core/ - router_pool 1462s END /stasis/core/ - router_pool Time: <1ms Result: PASS 1462s START /stasis/core/ - router 1462s END /stasis/core/ - router Time: <1ms Result: PASS 1462s START /stasis/core/ - cache_eid_aggregate 1462s END /stasis/core/ - cache_eid_aggregate Time: <1ms Result: PASS 1462s START /stasis/core/ - cache_dump 1462s END /stasis/core/ - cache_dump Time: <1ms Result: PASS 1462s START /stasis/core/ - cache 1462s END /stasis/core/ - cache Time: <1ms Result: PASS 1462s START /stasis/core/ - cache_filter 1462s END /stasis/core/ - cache_filter Time: 100ms Result: PASS 1462s START /stasis/core/ - forward 1462s END /stasis/core/ - forward Time: <1ms Result: PASS 1462s START /stasis/core/ - unsubscribe_stops_messages 1462s END /stasis/core/ - unsubscribe_stops_messages Time: 100ms Result: PASS 1462s START /stasis/core/ - publish_pool 1462s END /stasis/core/ - publish_pool Time: <1ms Result: PASS 1462s START /stasis/core/ - publish_sync 1462s END /stasis/core/ - publish_sync Time: <1ms Result: PASS 1462s START /stasis/core/ - publish 1462s END /stasis/core/ - publish Time: <1ms Result: PASS 1462s START /stasis/core/ - subscription_pool_messages 1462s END /stasis/core/ - subscription_pool_messages Time: <1ms Result: PASS 1462s START /stasis/core/ - subscription_messages 1462s END /stasis/core/ - subscription_messages Time: <1ms Result: PASS 1462s START /stasis/core/ - message 1462s END /stasis/core/ - message Time: <1ms Result: PASS 1462s START /stasis/core/ - message_type 1462s END /stasis/core/ - message_type Time: <1ms Result: PASS 1462s START /stasis/core/filtering/ - combo_filters 1462s [test_stasis.c:dump_consumer:2198]: Messages received: 7 Final? yes 1462s [test_stasis.c:dump_consumer:2202]: Message type received: stasis_subscription_change_type Subscribe 1462s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageType1 Pass 1462s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageType2 Pass 1462s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageAMI Pass 1462s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageAMIEVENT Pass 1462s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageJSON Pass 1462s [test_stasis.c:dump_consumer:2202]: Message type received: stasis_subscription_change_type Unsubscribe 1462s END /stasis/core/filtering/ - combo_filters Time: <1ms Result: PASS 1462s START /stasis/core/filtering/ - formatter_filters 1462s [test_stasis.c:dump_consumer:2198]: Messages received: 7 Final? yes 1462s [test_stasis.c:dump_consumer:2202]: Message type received: stasis_subscription_change_type Subscribe 1462s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageAMI Pass 1462s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageJSON Pass 1462s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageAMIEVENT Pass 1462s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageAMIEVENT Pass2 1462s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageEVENT Pass 1462s [test_stasis.c:dump_consumer:2202]: Message type received: stasis_subscription_change_type Unsubscribe 1462s END /stasis/core/filtering/ - formatter_filters Time: <1ms Result: PASS 1462s START /stasis/core/filtering/ - type_filters 1462s [test_stasis.c:dump_consumer:2198]: Messages received: 5 Final? yes 1462s [test_stasis.c:dump_consumer:2202]: Message type received: stasis_subscription_change_type Subscribe 1462s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageType1 Pass 1462s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageType2 Pass 1462s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageType2 Pass2 1462s [test_stasis.c:dump_consumer:2202]: Message type received: stasis_subscription_change_type Unsubscribe 1462s END /stasis/core/filtering/ - type_filters Time: <1ms Result: PASS 1462s START /stasis/core/state/ - explicit_publish 1462s END /stasis/core/state/ - explicit_publish Time: 31ms Result: PASS 1462s START /stasis/core/state/ - implicit_publish 1462s END /stasis/core/state/ - implicit_publish Time: 21ms Result: PASS 1462s START /stasis/endpoints/ - channel_messages 1462s END /stasis/endpoints/ - channel_messages Time: <1ms Result: PASS 1462s START /stasis/endpoints/ - cache_clear 1462s END /stasis/endpoints/ - cache_clear Time: <1ms Result: PASS 1462s START /stasis/endpoints/ - state_changes 1462s END /stasis/endpoints/ - state_changes Time: <1ms Result: PASS 1462s START /stasis/res/ - app_invoke_dne 1462s END /stasis/res/ - app_invoke_dne Time: <1ms Result: PASS 1462s START /stasis/res/ - app_invoke_one 1462s END /stasis/res/ - app_invoke_one Time: <1ms Result: PASS 1462s START /stasis/res/ - app_replaced 1462s END /stasis/res/ - app_replaced Time: <1ms Result: PASS 1462s 1462s 658 Test(s) Executed 633 Passed 25 Failed 1462s 'U' option is not compatible with remote console mode and has no effect. 1462s 1462s Results Generated Successfully: /tmp/autopkgtest.VZH8Xz/build.w4D/src/debian/tests/testmods/output/results.txt 1462s 'U' option is not compatible with remote console mode and has no effect. 1462s 1462s Some test modules were not loaded: 1462s 20a21 1462s > test_cel.so 1462s 53a55 1462s > test_message.so 1462s Manually disabled: 1462s test_message 1462s test_cel 1462s 1462s 'U' option is not compatible with remote console mode and has no effect. 1462s 1464s autopkgtest [21:53:32]: test asttestmods: -----------------------] 1464s asttestmods PASS 1464s autopkgtest [21:53:32]: test asttestmods: - - - - - - - - - - results - - - - - - - - - - 1464s autopkgtest [21:53:32]: test amr: preparing testbed 2619s autopkgtest [22:12:47]: testbed dpkg architecture: amd64 2619s autopkgtest [22:12:47]: testbed apt version: 2.7.14build2 2619s autopkgtest [22:12:47]: @@@@@@@@@@@@@@@@@@@@ test bed setup 2620s Get:1 http://ftpmaster.internal/ubuntu noble-proposed InRelease [117 kB] 2620s Get:2 http://ftpmaster.internal/ubuntu noble-proposed/multiverse Sources [10.6 kB] 2620s Get:3 http://ftpmaster.internal/ubuntu noble-proposed/restricted Sources [4680 B] 2620s Get:4 http://ftpmaster.internal/ubuntu noble-proposed/main Sources [358 kB] 2620s Get:5 http://ftpmaster.internal/ubuntu noble-proposed/universe Sources [831 kB] 2620s Get:6 http://ftpmaster.internal/ubuntu noble-proposed/main i386 Packages [269 kB] 2620s Get:7 http://ftpmaster.internal/ubuntu noble-proposed/main amd64 Packages [357 kB] 2620s Get:8 http://ftpmaster.internal/ubuntu noble-proposed/main amd64 c-n-f Metadata [3508 B] 2620s Get:9 http://ftpmaster.internal/ubuntu noble-proposed/restricted amd64 Packages [16.3 kB] 2620s Get:10 http://ftpmaster.internal/ubuntu noble-proposed/restricted i386 Packages [5016 B] 2620s Get:11 http://ftpmaster.internal/ubuntu noble-proposed/restricted amd64 c-n-f Metadata [116 B] 2620s Get:12 http://ftpmaster.internal/ubuntu noble-proposed/universe i386 Packages [449 kB] 2620s Get:13 http://ftpmaster.internal/ubuntu noble-proposed/universe amd64 Packages [1044 kB] 2620s Get:14 http://ftpmaster.internal/ubuntu noble-proposed/universe amd64 c-n-f Metadata [9396 B] 2620s Get:15 http://ftpmaster.internal/ubuntu noble-proposed/multiverse amd64 Packages [9440 B] 2620s Get:16 http://ftpmaster.internal/ubuntu noble-proposed/multiverse i386 Packages [2044 B] 2620s Get:17 http://ftpmaster.internal/ubuntu noble-proposed/multiverse amd64 c-n-f Metadata [196 B] 2622s Fetched 3486 kB in 1s (5178 kB/s) 2622s Reading package lists... 2624s Reading package lists... 2624s Building dependency tree... 2624s Reading state information... 2624s Calculating upgrade... 2624s The following packages will be upgraded: 2624s bash curl grub-common grub-pc grub-pc-bin grub2-common libcurl3t64-gnutls 2624s libcurl4t64 libpython3.12-minimal libpython3.12-stdlib libsasl2-2 2624s libsasl2-modules libsasl2-modules-db python3-gi python3.12 2624s python3.12-minimal shim-signed 2624s 17 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 2624s Need to get 12.6 MB of archives. 2624s After this operation, 34.8 kB disk space will be freed. 2624s Get:1 http://ftpmaster.internal/ubuntu noble/main amd64 bash amd64 5.2.21-2ubuntu4 [794 kB] 2624s Get:2 http://ftpmaster.internal/ubuntu noble/main amd64 python3.12 amd64 3.12.2-5ubuntu3 [644 kB] 2624s Get:3 http://ftpmaster.internal/ubuntu noble/main amd64 libpython3.12-stdlib amd64 3.12.2-5ubuntu3 [2067 kB] 2625s Get:4 http://ftpmaster.internal/ubuntu noble/main amd64 python3.12-minimal amd64 3.12.2-5ubuntu3 [2337 kB] 2625s Get:5 http://ftpmaster.internal/ubuntu noble/main amd64 libpython3.12-minimal amd64 3.12.2-5ubuntu3 [833 kB] 2625s Get:6 http://ftpmaster.internal/ubuntu noble/main amd64 python3-gi amd64 3.48.2-1 [232 kB] 2625s Get:7 http://ftpmaster.internal/ubuntu noble-proposed/main amd64 curl amd64 8.5.0-2ubuntu10 [227 kB] 2625s Get:8 http://ftpmaster.internal/ubuntu noble-proposed/main amd64 libcurl4t64 amd64 8.5.0-2ubuntu10 [340 kB] 2625s Get:9 http://ftpmaster.internal/ubuntu noble/main amd64 grub-pc amd64 2.12-1ubuntu7 [137 kB] 2625s Get:10 http://ftpmaster.internal/ubuntu noble/main amd64 grub2-common amd64 2.12-1ubuntu7 [669 kB] 2625s Get:11 http://ftpmaster.internal/ubuntu noble/main amd64 grub-pc-bin amd64 2.12-1ubuntu7 [1097 kB] 2625s Get:12 http://ftpmaster.internal/ubuntu noble/main amd64 grub-common amd64 2.12-1ubuntu7 [2120 kB] 2625s Get:13 http://ftpmaster.internal/ubuntu noble-proposed/main amd64 libcurl3t64-gnutls amd64 8.5.0-2ubuntu10 [333 kB] 2625s Get:14 http://ftpmaster.internal/ubuntu noble/main amd64 libsasl2-modules-db amd64 2.1.28+dfsg1-5ubuntu3 [20.3 kB] 2625s Get:15 http://ftpmaster.internal/ubuntu noble/main amd64 libsasl2-2 amd64 2.1.28+dfsg1-5ubuntu3 [53.2 kB] 2625s Get:16 http://ftpmaster.internal/ubuntu noble/main amd64 libsasl2-modules amd64 2.1.28+dfsg1-5ubuntu3 [69.7 kB] 2625s Get:17 http://ftpmaster.internal/ubuntu noble/main amd64 shim-signed amd64 1.58+15.8-0ubuntu1 [665 kB] 2625s Preconfiguring packages ... 2625s Fetched 12.6 MB in 0s (78.7 MB/s) 2625s (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 ... 105900 files and directories currently installed.) 2625s Preparing to unpack .../bash_5.2.21-2ubuntu4_amd64.deb ... 2625s Unpacking bash (5.2.21-2ubuntu4) over (5.2.21-2ubuntu2) ... 2625s Setting up bash (5.2.21-2ubuntu4) ... 2625s update-alternatives: using /usr/share/man/man7/bash-builtins.7.gz to provide /usr/share/man/man7/builtins.7.gz (builtins.7.gz) in auto mode 2625s (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 ... 105900 files and directories currently installed.) 2625s Preparing to unpack .../00-python3.12_3.12.2-5ubuntu3_amd64.deb ... 2625s Unpacking python3.12 (3.12.2-5ubuntu3) over (3.12.2-4build4) ... 2625s Preparing to unpack .../01-libpython3.12-stdlib_3.12.2-5ubuntu3_amd64.deb ... 2626s Unpacking libpython3.12-stdlib:amd64 (3.12.2-5ubuntu3) over (3.12.2-4build4) ... 2626s Preparing to unpack .../02-python3.12-minimal_3.12.2-5ubuntu3_amd64.deb ... 2626s Unpacking python3.12-minimal (3.12.2-5ubuntu3) over (3.12.2-4build4) ... 2626s Preparing to unpack .../03-libpython3.12-minimal_3.12.2-5ubuntu3_amd64.deb ... 2626s Unpacking libpython3.12-minimal:amd64 (3.12.2-5ubuntu3) over (3.12.2-4build4) ... 2626s Preparing to unpack .../04-python3-gi_3.48.2-1_amd64.deb ... 2626s Unpacking python3-gi (3.48.2-1) over (3.48.1-1build1) ... 2626s Preparing to unpack .../05-curl_8.5.0-2ubuntu10_amd64.deb ... 2626s Unpacking curl (8.5.0-2ubuntu10) over (8.5.0-2ubuntu9) ... 2626s Preparing to unpack .../06-libcurl4t64_8.5.0-2ubuntu10_amd64.deb ... 2626s Unpacking libcurl4t64:amd64 (8.5.0-2ubuntu10) over (8.5.0-2ubuntu9) ... 2626s Preparing to unpack .../07-grub-pc_2.12-1ubuntu7_amd64.deb ... 2626s Unpacking grub-pc (2.12-1ubuntu7) over (2.12-1ubuntu6) ... 2626s Preparing to unpack .../08-grub2-common_2.12-1ubuntu7_amd64.deb ... 2626s Unpacking grub2-common (2.12-1ubuntu7) over (2.12-1ubuntu6) ... 2626s Preparing to unpack .../09-grub-pc-bin_2.12-1ubuntu7_amd64.deb ... 2626s Unpacking grub-pc-bin (2.12-1ubuntu7) over (2.12-1ubuntu6) ... 2626s Preparing to unpack .../10-grub-common_2.12-1ubuntu7_amd64.deb ... 2627s Unpacking grub-common (2.12-1ubuntu7) over (2.12-1ubuntu6) ... 2627s Preparing to unpack .../11-libcurl3t64-gnutls_8.5.0-2ubuntu10_amd64.deb ... 2627s Unpacking libcurl3t64-gnutls:amd64 (8.5.0-2ubuntu10) over (8.5.0-2ubuntu9) ... 2627s Preparing to unpack .../12-libsasl2-modules-db_2.1.28+dfsg1-5ubuntu3_amd64.deb ... 2627s Unpacking libsasl2-modules-db:amd64 (2.1.28+dfsg1-5ubuntu3) over (2.1.28+dfsg1-5ubuntu2) ... 2627s Preparing to unpack .../13-libsasl2-2_2.1.28+dfsg1-5ubuntu3_amd64.deb ... 2627s Unpacking libsasl2-2:amd64 (2.1.28+dfsg1-5ubuntu3) over (2.1.28+dfsg1-5ubuntu2) ... 2627s Preparing to unpack .../14-libsasl2-modules_2.1.28+dfsg1-5ubuntu3_amd64.deb ... 2627s Unpacking libsasl2-modules:amd64 (2.1.28+dfsg1-5ubuntu3) over (2.1.28+dfsg1-5ubuntu2) ... 2627s Preparing to unpack .../15-shim-signed_1.58+15.8-0ubuntu1_amd64.deb ... 2627s Unpacking shim-signed (1.58+15.8-0ubuntu1) over (1.57+15.8-0ubuntu1) ... 2627s Setting up libcurl4t64:amd64 (8.5.0-2ubuntu10) ... 2627s Setting up libsasl2-modules:amd64 (2.1.28+dfsg1-5ubuntu3) ... 2627s Setting up libpython3.12-minimal:amd64 (3.12.2-5ubuntu3) ... 2627s Setting up libcurl3t64-gnutls:amd64 (8.5.0-2ubuntu10) ... 2627s Setting up libsasl2-modules-db:amd64 (2.1.28+dfsg1-5ubuntu3) ... 2627s Setting up grub-common (2.12-1ubuntu7) ... 2627s update-rc.d: warning: start and stop actions are no longer supported; falling back to defaults 2628s Setting up python3-gi (3.48.2-1) ... 2628s Setting up libsasl2-2:amd64 (2.1.28+dfsg1-5ubuntu3) ... 2628s Setting up curl (8.5.0-2ubuntu10) ... 2628s Setting up python3.12-minimal (3.12.2-5ubuntu3) ... 2629s Setting up libpython3.12-stdlib:amd64 (3.12.2-5ubuntu3) ... 2629s Setting up grub2-common (2.12-1ubuntu7) ... 2629s Setting up python3.12 (3.12.2-5ubuntu3) ... 2630s Setting up grub-pc-bin (2.12-1ubuntu7) ... 2630s Setting up shim-signed (1.58+15.8-0ubuntu1) ... 2630s Installing for x86_64-efi platform. 2630s grub-install: warning: EFI variables cannot be set on this system. 2630s grub-install: warning: You will have to complete the GRUB setup manually. 2630s Installation finished. No error reported. 2630s Setting up grub-pc (2.12-1ubuntu7) ... 2630s Installing for i386-pc platform. 2631s Installation finished. No error reported. 2631s Sourcing file `/etc/default/grub' 2631s Sourcing file `/etc/default/grub.d/50-cloudimg-settings.cfg' 2631s Sourcing file `/etc/default/grub.d/90-autopkgtest.cfg' 2631s Generating grub configuration file ... 2631s Found linux image: /boot/vmlinuz-6.8.0-22-generic 2631s Found initrd image: /boot/initrd.img-6.8.0-22-generic 2631s Found linux image: /boot/vmlinuz-6.8.0-11-generic 2631s Found initrd image: /boot/initrd.img-6.8.0-11-generic 2631s Warning: os-prober will not be executed to detect other bootable partitions. 2631s Systems on them will not be added to the GRUB boot configuration. 2631s Check GRUB_DISABLE_OS_PROBER documentation entry. 2631s Adding boot menu entry for UEFI Firmware Settings ... 2631s done 2631s Processing triggers for install-info (7.1-3build2) ... 2631s Processing triggers for libc-bin (2.39-0ubuntu8) ... 2631s Processing triggers for systemd (255.4-1ubuntu7) ... 2631s Processing triggers for man-db (2.12.0-4build1) ... 2633s Processing triggers for debianutils (5.17build1) ... 2633s Reading package lists... 2633s Building dependency tree... 2633s Reading state information... 2633s The following packages will be REMOVED: 2633s linux-headers-6.8.0-11* linux-headers-6.8.0-11-generic* 2633s linux-image-6.8.0-11-generic* linux-modules-6.8.0-11-generic* 2634s 0 upgraded, 0 newly installed, 4 to remove and 0 not upgraded. 2634s After this operation, 167 MB disk space will be freed. 2634s (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 ... 105901 files and directories currently installed.) 2634s Removing linux-headers-6.8.0-11-generic (6.8.0-11.11) ... 2634s Removing linux-headers-6.8.0-11 (6.8.0-11.11) ... 2636s Removing linux-image-6.8.0-11-generic (6.8.0-11.11) ... 2636s I: /boot/vmlinuz.old is now a symlink to vmlinuz-6.8.0-22-generic 2636s I: /boot/initrd.img.old is now a symlink to initrd.img-6.8.0-22-generic 2636s /etc/kernel/postrm.d/initramfs-tools: 2636s update-initramfs: Deleting /boot/initrd.img-6.8.0-11-generic 2637s /etc/kernel/postrm.d/zz-update-grub: 2637s Sourcing file `/etc/default/grub' 2637s Sourcing file `/etc/default/grub.d/50-cloudimg-settings.cfg' 2637s Sourcing file `/etc/default/grub.d/90-autopkgtest.cfg' 2637s Generating grub configuration file ... 2637s Found linux image: /boot/vmlinuz-6.8.0-22-generic 2637s Found initrd image: /boot/initrd.img-6.8.0-22-generic 2637s Warning: os-prober will not be executed to detect other bootable partitions. 2637s Systems on them will not be added to the GRUB boot configuration. 2637s Check GRUB_DISABLE_OS_PROBER documentation entry. 2637s Adding boot menu entry for UEFI Firmware Settings ... 2637s done 2637s Removing linux-modules-6.8.0-11-generic (6.8.0-11.11) ... 2637s (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 ... 74382 files and directories currently installed.) 2637s Purging configuration files for linux-image-6.8.0-11-generic (6.8.0-11.11) ... 2637s Purging configuration files for linux-modules-6.8.0-11-generic (6.8.0-11.11) ... 2638s Hit:1 http://ftpmaster.internal/ubuntu noble-proposed InRelease 2638s Hit:2 http://ftpmaster.internal/ubuntu noble InRelease 2638s Hit:3 http://ftpmaster.internal/ubuntu noble-updates InRelease 2638s Hit:4 http://ftpmaster.internal/ubuntu noble-security InRelease 2639s Reading package lists... 2639s Reading package lists... 2639s Building dependency tree... 2639s Reading state information... 2639s Calculating upgrade... 2639s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 2639s Reading package lists... 2640s Building dependency tree... 2640s Reading state information... 2640s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 2640s autopkgtest [22:13:08]: rebooting testbed after setup commands that affected boot 2779s autopkgtest-virt-ssh: WARNING: ssh connection failed. Retrying in 3 seconds... 2786s Reading package lists... 2786s Building dependency tree... 2786s Reading state information... 2787s Starting pkgProblemResolver with broken count: 0 2787s Starting 2 pkgProblemResolver with broken count: 0 2787s Done 2787s The following additional packages will be installed: 2787s asterisk asterisk-config asterisk-core-sounds-en asterisk-core-sounds-en-gsm 2787s asterisk-modules freetds-common libasound2-data libasound2t64 2787s libc-client2007e libcodec2-1.2 libevent-2.1-7t64 libgmime-3.0-0t64 libgsm1 2787s libical3t64 libiksemel3 libjack-jackd2-0 libltdl7 liblua5.1-0 libneon27t64 2787s libodbc2 libogg0 libopencore-amrnb0 libopencore-amrwb0 libopus0 libopusenc0 2787s libopusfile0 libportaudio2 libpq5 libradcli4 libresample1 libsamplerate0 2787s libsnmp-base libsnmp40t64 libspandsp2t64 libspeex1 libspeexdsp1 libsrtp2-1 2787s libsybdb5 libunbound8 liburiparser1 libvo-amrwbenc0 libvorbis0a 2787s libvorbisenc2 libvorbisfile3 libxslt1.1 mlock 2787s Suggested packages: 2787s asterisk-dahdi asterisk-dev asterisk-doc asterisk-ooh323 asterisk-opus 2787s alsa-utils libasound2-plugins uw-mailutils jackd2 odbc-postgresql tdsodbc 2787s opus-tools snmp-mibs-downloader speex 2787s Recommended packages: 2787s asterisk-moh-opsound-gsm sox alsa-ucm-conf alsa-topology-conf 2787s The following NEW packages will be installed: 2787s asterisk asterisk-config asterisk-core-sounds-en asterisk-core-sounds-en-gsm 2787s asterisk-modules autopkgtest-satdep freetds-common libasound2-data 2787s libasound2t64 libc-client2007e libcodec2-1.2 libevent-2.1-7t64 2787s libgmime-3.0-0t64 libgsm1 libical3t64 libiksemel3 libjack-jackd2-0 libltdl7 2787s liblua5.1-0 libneon27t64 libodbc2 libogg0 libopencore-amrnb0 2787s libopencore-amrwb0 libopus0 libopusenc0 libopusfile0 libportaudio2 libpq5 2787s libradcli4 libresample1 libsamplerate0 libsnmp-base libsnmp40t64 2787s libspandsp2t64 libspeex1 libspeexdsp1 libsrtp2-1 libsybdb5 libunbound8 2787s liburiparser1 libvo-amrwbenc0 libvorbis0a libvorbisenc2 libvorbisfile3 2787s libxslt1.1 mlock 2787s 0 upgraded, 47 newly installed, 0 to remove and 0 not upgraded. 2787s Need to get 24.8 MB/24.8 MB of archives. 2787s After this operation, 64.9 MB of additional disk space will be used. 2787s Get:1 /tmp/autopkgtest.VZH8Xz/2-autopkgtest-satdep.deb autopkgtest-satdep amd64 0 [716 B] 2787s Get:2 http://ftpmaster.internal/ubuntu noble/universe amd64 asterisk-config all 1:20.6.0~dfsg+~cs6.13.40431414-2build4 [242 kB] 2787s Get:3 http://ftpmaster.internal/ubuntu noble/universe amd64 asterisk-core-sounds-en-gsm all 1.6.1-1 [2417 kB] 2787s Get:4 http://ftpmaster.internal/ubuntu noble/universe amd64 asterisk-core-sounds-en all 1.6.1-1 [20.6 kB] 2787s Get:5 http://ftpmaster.internal/ubuntu noble-updates/universe amd64 mlock amd64 8:2007f~dfsg-7build1 [12.2 kB] 2787s Get:6 http://ftpmaster.internal/ubuntu noble-updates/universe amd64 libc-client2007e amd64 8:2007f~dfsg-7build1 [645 kB] 2787s Get:7 http://ftpmaster.internal/ubuntu noble/universe amd64 libcodec2-1.2 amd64 1.2.0-2 [8999 kB] 2788s Get:8 http://ftpmaster.internal/ubuntu noble/universe amd64 libgmime-3.0-0t64 amd64 3.2.13+dfsg-2.1build2 [176 kB] 2788s Get:9 http://ftpmaster.internal/ubuntu noble/universe amd64 libgsm1 amd64 1.0.22-1 [27.9 kB] 2788s Get:10 http://ftpmaster.internal/ubuntu noble/main amd64 libical3t64 amd64 3.0.17-1.1build3 [305 kB] 2788s Get:11 http://ftpmaster.internal/ubuntu noble/universe amd64 libiksemel3 amd64 1.4-4build2 [28.0 kB] 2788s Get:12 http://ftpmaster.internal/ubuntu noble/main amd64 libopus0 amd64 1.4-1 [208 kB] 2788s Get:13 http://ftpmaster.internal/ubuntu noble/main amd64 libsamplerate0 amd64 0.2.2-4 [1343 kB] 2788s Get:14 http://ftpmaster.internal/ubuntu noble/main amd64 libjack-jackd2-0 amd64 1.9.21~dfsg-3ubuntu3 [289 kB] 2788s Get:15 http://ftpmaster.internal/ubuntu noble/universe amd64 liblua5.1-0 amd64 5.1.5-9build2 [120 kB] 2788s Get:16 http://ftpmaster.internal/ubuntu noble/universe amd64 libneon27t64 amd64 0.33.0-1.1build2 [102 kB] 2788s Get:17 http://ftpmaster.internal/ubuntu noble/main amd64 libltdl7 amd64 2.4.7-7 [40.5 kB] 2788s Get:18 http://ftpmaster.internal/ubuntu noble/main amd64 libodbc2 amd64 2.3.12-1build2 [158 kB] 2788s Get:19 http://ftpmaster.internal/ubuntu noble/main amd64 libogg0 amd64 1.3.5-3 [22.4 kB] 2788s Get:20 http://ftpmaster.internal/ubuntu noble/universe amd64 libopencore-amrnb0 amd64 0.1.6-1 [97.9 kB] 2788s Get:21 http://ftpmaster.internal/ubuntu noble/universe amd64 libopencore-amrwb0 amd64 0.1.6-1 [53.0 kB] 2788s Get:22 http://ftpmaster.internal/ubuntu noble/universe amd64 libopusenc0 amd64 0.2.1-2 [25.2 kB] 2788s Get:23 http://ftpmaster.internal/ubuntu noble/universe amd64 libopusfile0 amd64 0.12-4build2 [44.7 kB] 2788s Get:24 http://ftpmaster.internal/ubuntu noble/main amd64 libasound2-data all 1.2.11-1build2 [21.0 kB] 2788s Get:25 http://ftpmaster.internal/ubuntu noble/main amd64 libasound2t64 amd64 1.2.11-1build2 [399 kB] 2788s Get:26 http://ftpmaster.internal/ubuntu noble/universe amd64 libportaudio2 amd64 19.6.0-1.2build3 [67.9 kB] 2788s Get:27 http://ftpmaster.internal/ubuntu noble/main amd64 libpq5 amd64 16.2-1ubuntu3 [138 kB] 2788s Get:28 http://ftpmaster.internal/ubuntu noble/universe amd64 libradcli4 amd64 1.2.11-1build3 [40.5 kB] 2788s Get:29 http://ftpmaster.internal/ubuntu noble/universe amd64 libresample1 amd64 0.1.3-6 [8806 B] 2788s Get:30 http://ftpmaster.internal/ubuntu noble/main amd64 libsnmp-base all 5.9.4+dfsg-1.1ubuntu3 [206 kB] 2788s Get:31 http://ftpmaster.internal/ubuntu noble/main amd64 libsnmp40t64 amd64 5.9.4+dfsg-1.1ubuntu3 [1066 kB] 2788s Get:32 http://ftpmaster.internal/ubuntu noble/universe amd64 libspandsp2t64 amd64 0.0.6+dfsg-2.1build1 [311 kB] 2788s Get:33 http://ftpmaster.internal/ubuntu noble/main amd64 libspeex1 amd64 1.2.1-2ubuntu1 [58.8 kB] 2788s Get:34 http://ftpmaster.internal/ubuntu noble/main amd64 libspeexdsp1 amd64 1.2.1-1ubuntu3 [43.1 kB] 2788s Get:35 http://ftpmaster.internal/ubuntu noble/universe amd64 libsrtp2-1 amd64 2.5.0-3 [41.3 kB] 2788s Get:36 http://ftpmaster.internal/ubuntu noble/main amd64 freetds-common all 1.3.17+ds-2build3 [26.9 kB] 2788s Get:37 http://ftpmaster.internal/ubuntu noble/main amd64 libsybdb5 amd64 1.3.17+ds-2build3 [192 kB] 2788s Get:38 http://ftpmaster.internal/ubuntu noble/main amd64 libevent-2.1-7t64 amd64 2.1.12-stable-9ubuntu2 [145 kB] 2788s Get:39 http://ftpmaster.internal/ubuntu noble/main amd64 libunbound8 amd64 1.19.2-1ubuntu3 [440 kB] 2788s Get:40 http://ftpmaster.internal/ubuntu noble/universe amd64 libvo-amrwbenc0 amd64 0.1.3-2 [68.2 kB] 2788s Get:41 http://ftpmaster.internal/ubuntu noble/main amd64 libvorbis0a amd64 1.3.7-1build2 [99.2 kB] 2788s Get:42 http://ftpmaster.internal/ubuntu noble/main amd64 libvorbisenc2 amd64 1.3.7-1build2 [82.6 kB] 2788s Get:43 http://ftpmaster.internal/ubuntu noble/main amd64 libvorbisfile3 amd64 1.3.7-1build2 [17.1 kB] 2788s Get:44 http://ftpmaster.internal/ubuntu noble/universe amd64 asterisk-modules amd64 1:20.6.0~dfsg+~cs6.13.40431414-2build4 [3177 kB] 2788s Get:45 http://ftpmaster.internal/ubuntu noble/universe amd64 liburiparser1 amd64 0.9.7+dfsg-2 [35.9 kB] 2788s Get:46 http://ftpmaster.internal/ubuntu noble/main amd64 libxslt1.1 amd64 1.1.39-0exp1build1 [167 kB] 2788s Get:47 http://ftpmaster.internal/ubuntu noble/universe amd64 asterisk amd64 1:20.6.0~dfsg+~cs6.13.40431414-2build4 [2601 kB] 2788s Fetched 24.8 MB in 0s (68.4 MB/s) 2788s Selecting previously unselected package asterisk-config. 2788s (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 ... 74381 files and directories currently installed.) 2788s Preparing to unpack .../00-asterisk-config_1%3a20.6.0~dfsg+~cs6.13.40431414-2build4_all.deb ... 2788s Unpacking asterisk-config (1:20.6.0~dfsg+~cs6.13.40431414-2build4) ... 2788s Selecting previously unselected package asterisk-core-sounds-en-gsm. 2788s Preparing to unpack .../01-asterisk-core-sounds-en-gsm_1.6.1-1_all.deb ... 2788s Unpacking asterisk-core-sounds-en-gsm (1.6.1-1) ... 2789s Selecting previously unselected package asterisk-core-sounds-en. 2789s Preparing to unpack .../02-asterisk-core-sounds-en_1.6.1-1_all.deb ... 2789s Unpacking asterisk-core-sounds-en (1.6.1-1) ... 2789s Selecting previously unselected package mlock. 2789s Preparing to unpack .../03-mlock_8%3a2007f~dfsg-7build1_amd64.deb ... 2789s Unpacking mlock (8:2007f~dfsg-7build1) ... 2789s Selecting previously unselected package libc-client2007e. 2789s Preparing to unpack .../04-libc-client2007e_8%3a2007f~dfsg-7build1_amd64.deb ... 2789s Unpacking libc-client2007e (8:2007f~dfsg-7build1) ... 2789s Selecting previously unselected package libcodec2-1.2:amd64. 2789s Preparing to unpack .../05-libcodec2-1.2_1.2.0-2_amd64.deb ... 2789s Unpacking libcodec2-1.2:amd64 (1.2.0-2) ... 2789s Selecting previously unselected package libgmime-3.0-0t64:amd64. 2789s Preparing to unpack .../06-libgmime-3.0-0t64_3.2.13+dfsg-2.1build2_amd64.deb ... 2789s Unpacking libgmime-3.0-0t64:amd64 (3.2.13+dfsg-2.1build2) ... 2789s Selecting previously unselected package libgsm1:amd64. 2789s Preparing to unpack .../07-libgsm1_1.0.22-1_amd64.deb ... 2789s Unpacking libgsm1:amd64 (1.0.22-1) ... 2789s Selecting previously unselected package libical3t64:amd64. 2789s Preparing to unpack .../08-libical3t64_3.0.17-1.1build3_amd64.deb ... 2789s Unpacking libical3t64:amd64 (3.0.17-1.1build3) ... 2789s Selecting previously unselected package libiksemel3:amd64. 2789s Preparing to unpack .../09-libiksemel3_1.4-4build2_amd64.deb ... 2789s Unpacking libiksemel3:amd64 (1.4-4build2) ... 2789s Selecting previously unselected package libopus0:amd64. 2789s Preparing to unpack .../10-libopus0_1.4-1_amd64.deb ... 2789s Unpacking libopus0:amd64 (1.4-1) ... 2789s Selecting previously unselected package libsamplerate0:amd64. 2789s Preparing to unpack .../11-libsamplerate0_0.2.2-4_amd64.deb ... 2789s Unpacking libsamplerate0:amd64 (0.2.2-4) ... 2789s Selecting previously unselected package libjack-jackd2-0:amd64. 2789s Preparing to unpack .../12-libjack-jackd2-0_1.9.21~dfsg-3ubuntu3_amd64.deb ... 2789s Unpacking libjack-jackd2-0:amd64 (1.9.21~dfsg-3ubuntu3) ... 2789s Selecting previously unselected package liblua5.1-0:amd64. 2789s Preparing to unpack .../13-liblua5.1-0_5.1.5-9build2_amd64.deb ... 2789s Unpacking liblua5.1-0:amd64 (5.1.5-9build2) ... 2789s Selecting previously unselected package libneon27t64:amd64. 2789s Preparing to unpack .../14-libneon27t64_0.33.0-1.1build2_amd64.deb ... 2789s Unpacking libneon27t64:amd64 (0.33.0-1.1build2) ... 2789s Selecting previously unselected package libltdl7:amd64. 2789s Preparing to unpack .../15-libltdl7_2.4.7-7_amd64.deb ... 2789s Unpacking libltdl7:amd64 (2.4.7-7) ... 2789s Selecting previously unselected package libodbc2:amd64. 2789s Preparing to unpack .../16-libodbc2_2.3.12-1build2_amd64.deb ... 2789s Unpacking libodbc2:amd64 (2.3.12-1build2) ... 2789s Selecting previously unselected package libogg0:amd64. 2789s Preparing to unpack .../17-libogg0_1.3.5-3_amd64.deb ... 2789s Unpacking libogg0:amd64 (1.3.5-3) ... 2789s Selecting previously unselected package libopencore-amrnb0:amd64. 2789s Preparing to unpack .../18-libopencore-amrnb0_0.1.6-1_amd64.deb ... 2789s Unpacking libopencore-amrnb0:amd64 (0.1.6-1) ... 2789s Selecting previously unselected package libopencore-amrwb0:amd64. 2789s Preparing to unpack .../19-libopencore-amrwb0_0.1.6-1_amd64.deb ... 2789s Unpacking libopencore-amrwb0:amd64 (0.1.6-1) ... 2789s Selecting previously unselected package libopusenc0:amd64. 2789s Preparing to unpack .../20-libopusenc0_0.2.1-2_amd64.deb ... 2789s Unpacking libopusenc0:amd64 (0.2.1-2) ... 2789s Selecting previously unselected package libopusfile0:amd64. 2789s Preparing to unpack .../21-libopusfile0_0.12-4build2_amd64.deb ... 2789s Unpacking libopusfile0:amd64 (0.12-4build2) ... 2789s Selecting previously unselected package libasound2-data. 2789s Preparing to unpack .../22-libasound2-data_1.2.11-1build2_all.deb ... 2789s Unpacking libasound2-data (1.2.11-1build2) ... 2789s Selecting previously unselected package libasound2t64:amd64. 2789s Preparing to unpack .../23-libasound2t64_1.2.11-1build2_amd64.deb ... 2789s Unpacking libasound2t64:amd64 (1.2.11-1build2) ... 2789s Selecting previously unselected package libportaudio2:amd64. 2789s Preparing to unpack .../24-libportaudio2_19.6.0-1.2build3_amd64.deb ... 2789s Unpacking libportaudio2:amd64 (19.6.0-1.2build3) ... 2789s Selecting previously unselected package libpq5:amd64. 2789s Preparing to unpack .../25-libpq5_16.2-1ubuntu3_amd64.deb ... 2789s Unpacking libpq5:amd64 (16.2-1ubuntu3) ... 2789s Selecting previously unselected package libradcli4. 2789s Preparing to unpack .../26-libradcli4_1.2.11-1build3_amd64.deb ... 2789s Unpacking libradcli4 (1.2.11-1build3) ... 2789s Selecting previously unselected package libresample1. 2789s Preparing to unpack .../27-libresample1_0.1.3-6_amd64.deb ... 2789s Unpacking libresample1 (0.1.3-6) ... 2789s Selecting previously unselected package libsnmp-base. 2789s Preparing to unpack .../28-libsnmp-base_5.9.4+dfsg-1.1ubuntu3_all.deb ... 2789s Unpacking libsnmp-base (5.9.4+dfsg-1.1ubuntu3) ... 2789s Selecting previously unselected package libsnmp40t64:amd64. 2789s Preparing to unpack .../29-libsnmp40t64_5.9.4+dfsg-1.1ubuntu3_amd64.deb ... 2789s Unpacking libsnmp40t64:amd64 (5.9.4+dfsg-1.1ubuntu3) ... 2789s Selecting previously unselected package libspandsp2t64:amd64. 2789s Preparing to unpack .../30-libspandsp2t64_0.0.6+dfsg-2.1build1_amd64.deb ... 2789s Unpacking libspandsp2t64:amd64 (0.0.6+dfsg-2.1build1) ... 2789s Selecting previously unselected package libspeex1:amd64. 2789s Preparing to unpack .../31-libspeex1_1.2.1-2ubuntu1_amd64.deb ... 2789s Unpacking libspeex1:amd64 (1.2.1-2ubuntu1) ... 2789s Selecting previously unselected package libspeexdsp1:amd64. 2789s Preparing to unpack .../32-libspeexdsp1_1.2.1-1ubuntu3_amd64.deb ... 2789s Unpacking libspeexdsp1:amd64 (1.2.1-1ubuntu3) ... 2790s Selecting previously unselected package libsrtp2-1:amd64. 2790s Preparing to unpack .../33-libsrtp2-1_2.5.0-3_amd64.deb ... 2790s Unpacking libsrtp2-1:amd64 (2.5.0-3) ... 2790s Selecting previously unselected package freetds-common. 2790s Preparing to unpack .../34-freetds-common_1.3.17+ds-2build3_all.deb ... 2790s Unpacking freetds-common (1.3.17+ds-2build3) ... 2790s Selecting previously unselected package libsybdb5:amd64. 2790s Preparing to unpack .../35-libsybdb5_1.3.17+ds-2build3_amd64.deb ... 2790s Unpacking libsybdb5:amd64 (1.3.17+ds-2build3) ... 2790s Selecting previously unselected package libevent-2.1-7t64:amd64. 2790s Preparing to unpack .../36-libevent-2.1-7t64_2.1.12-stable-9ubuntu2_amd64.deb ... 2790s Unpacking libevent-2.1-7t64:amd64 (2.1.12-stable-9ubuntu2) ... 2790s Selecting previously unselected package libunbound8:amd64. 2790s Preparing to unpack .../37-libunbound8_1.19.2-1ubuntu3_amd64.deb ... 2790s Unpacking libunbound8:amd64 (1.19.2-1ubuntu3) ... 2790s Selecting previously unselected package libvo-amrwbenc0:amd64. 2790s Preparing to unpack .../38-libvo-amrwbenc0_0.1.3-2_amd64.deb ... 2790s Unpacking libvo-amrwbenc0:amd64 (0.1.3-2) ... 2790s Selecting previously unselected package libvorbis0a:amd64. 2790s Preparing to unpack .../39-libvorbis0a_1.3.7-1build2_amd64.deb ... 2790s Unpacking libvorbis0a:amd64 (1.3.7-1build2) ... 2790s Selecting previously unselected package libvorbisenc2:amd64. 2790s Preparing to unpack .../40-libvorbisenc2_1.3.7-1build2_amd64.deb ... 2790s Unpacking libvorbisenc2:amd64 (1.3.7-1build2) ... 2790s Selecting previously unselected package libvorbisfile3:amd64. 2790s Preparing to unpack .../41-libvorbisfile3_1.3.7-1build2_amd64.deb ... 2790s Unpacking libvorbisfile3:amd64 (1.3.7-1build2) ... 2790s Selecting previously unselected package asterisk-modules. 2790s Preparing to unpack .../42-asterisk-modules_1%3a20.6.0~dfsg+~cs6.13.40431414-2build4_amd64.deb ... 2790s Unpacking asterisk-modules (1:20.6.0~dfsg+~cs6.13.40431414-2build4) ... 2790s Selecting previously unselected package liburiparser1:amd64. 2790s Preparing to unpack .../43-liburiparser1_0.9.7+dfsg-2_amd64.deb ... 2790s Unpacking liburiparser1:amd64 (0.9.7+dfsg-2) ... 2790s Selecting previously unselected package libxslt1.1:amd64. 2790s Preparing to unpack .../44-libxslt1.1_1.1.39-0exp1build1_amd64.deb ... 2790s Unpacking libxslt1.1:amd64 (1.1.39-0exp1build1) ... 2790s Selecting previously unselected package asterisk. 2790s Preparing to unpack .../45-asterisk_1%3a20.6.0~dfsg+~cs6.13.40431414-2build4_amd64.deb ... 2790s Unpacking asterisk (1:20.6.0~dfsg+~cs6.13.40431414-2build4) ... 2790s Selecting previously unselected package autopkgtest-satdep. 2790s Preparing to unpack .../46-2-autopkgtest-satdep.deb ... 2790s Unpacking autopkgtest-satdep (0) ... 2790s Setting up libvo-amrwbenc0:amd64 (0.1.3-2) ... 2790s Setting up libneon27t64:amd64 (0.33.0-1.1build2) ... 2790s Setting up libogg0:amd64 (1.3.5-3) ... 2790s Setting up libspeex1:amd64 (1.2.1-2ubuntu1) ... 2790s Setting up libgsm1:amd64 (1.0.22-1) ... 2790s Setting up asterisk-core-sounds-en-gsm (1.6.1-1) ... 2790s Setting up libsnmp-base (5.9.4+dfsg-1.1ubuntu3) ... 2790s Setting up libcodec2-1.2:amd64 (1.2.0-2) ... 2790s Setting up mlock (8:2007f~dfsg-7build1) ... 2790s Setting up libsrtp2-1:amd64 (2.5.0-3) ... 2790s Setting up libpq5:amd64 (16.2-1ubuntu3) ... 2790s Setting up libevent-2.1-7t64:amd64 (2.1.12-stable-9ubuntu2) ... 2790s Setting up libasound2-data (1.2.11-1build2) ... 2790s Setting up libopencore-amrwb0:amd64 (0.1.6-1) ... 2790s Setting up libunbound8:amd64 (1.19.2-1ubuntu3) ... 2790s Setting up libasound2t64:amd64 (1.2.11-1build2) ... 2790s Setting up libradcli4 (1.2.11-1build3) ... 2790s Setting up libopus0:amd64 (1.4-1) ... 2790s Setting up asterisk-config (1:20.6.0~dfsg+~cs6.13.40431414-2build4) ... 2790s Setting up libvorbis0a:amd64 (1.3.7-1build2) ... 2790s Setting up libical3t64:amd64 (3.0.17-1.1build3) ... 2790s Setting up libltdl7:amd64 (2.4.7-7) ... 2790s Setting up asterisk-core-sounds-en (1.6.1-1) ... 2790s update-alternatives: using /usr/share/asterisk/sounds/en_US_f_Allison to provide /usr/share/asterisk/sounds/en (asterisk-prompt-en) in auto mode 2790s 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 2790s Setting up libiksemel3:amd64 (1.4-4build2) ... 2790s Setting up libodbc2:amd64 (2.3.12-1build2) ... 2790s Setting up liburiparser1:amd64 (0.9.7+dfsg-2) ... 2790s Setting up libspandsp2t64:amd64 (0.0.6+dfsg-2.1build1) ... 2790s Setting up libspeexdsp1:amd64 (1.2.1-1ubuntu3) ... 2790s Setting up liblua5.1-0:amd64 (5.1.5-9build2) ... 2790s Setting up libxslt1.1:amd64 (1.1.39-0exp1build1) ... 2790s Setting up libopencore-amrnb0:amd64 (0.1.6-1) ... 2790s Setting up libc-client2007e (8:2007f~dfsg-7build1) ... 2790s Setting up libresample1 (0.1.3-6) ... 2790s Setting up freetds-common (1.3.17+ds-2build3) ... 2790s Setting up libgmime-3.0-0t64:amd64 (3.2.13+dfsg-2.1build2) ... 2790s Setting up libsamplerate0:amd64 (0.2.2-4) ... 2790s Setting up libopusfile0:amd64 (0.12-4build2) ... 2790s Setting up libvorbisenc2:amd64 (1.3.7-1build2) ... 2790s Setting up libopusenc0:amd64 (0.2.1-2) ... 2790s Setting up libsnmp40t64:amd64 (5.9.4+dfsg-1.1ubuntu3) ... 2790s Setting up libsybdb5:amd64 (1.3.17+ds-2build3) ... 2790s Setting up libvorbisfile3:amd64 (1.3.7-1build2) ... 2790s Setting up libjack-jackd2-0:amd64 (1.9.21~dfsg-3ubuntu3) ... 2790s Setting up libportaudio2:amd64 (19.6.0-1.2build3) ... 2790s Setting up asterisk-modules (1:20.6.0~dfsg+~cs6.13.40431414-2build4) ... 2790s Setting up asterisk (1:20.6.0~dfsg+~cs6.13.40431414-2build4) ... 2790s Adding system user for Asterisk 2790s info: Adding user `asterisk' to group `dialout' ... 2791s info: Adding user `asterisk' to group `audio' ... 2791s Created symlink /etc/systemd/system/multi-user.target.wants/asterisk.service → /usr/lib/systemd/system/asterisk.service. 2792s Setting up autopkgtest-satdep (0) ... 2792s Processing triggers for man-db (2.12.0-4build1) ... 2794s Processing triggers for libc-bin (2.39-0ubuntu8) ... 2796s (Reading database ... 76302 files and directories currently installed.) 2796s Removing autopkgtest-satdep (0) ... 2805s autopkgtest [22:15:53]: test amr: [----------------------- 2805s 1 audio amr amr (AMR) 2805s 2 audio amrwb amrwb (AMR-WB) 2805s amr amrwb codec2 ulaw alaw gsm g726 g726aal2 adpcm slin8 slin12 slin16 slin24 slin32 slin44 slin48 slin96 slin192 lpc10 speex8 speex16 speex32 g722 opus 2805s amr - 23000 15000 15000 15000 15000 15000 15000 15000 9000 17000 17000 17000 17000 17000 17000 17000 17000 15000 15000 23000 23000 17250 15000 2805s amr amrwb codec2 ulaw alaw gsm g726 g726aal2 adpcm slin8 slin12 slin16 slin24 slin32 slin44 slin48 slin96 slin192 lpc10 speex8 speex16 speex32 g722 opus 2805s amrwb 23500 - 23500 23500 23500 23500 23500 23500 23500 17500 17500 9000 17000 17000 17000 17000 17000 17000 23500 23500 15000 23000 15000 14999 2806s autopkgtest [22:15:54]: test amr: -----------------------] 2806s autopkgtest [22:15:54]: test amr: - - - - - - - - - - results - - - - - - - - - - 2806s amr PASS 2806s autopkgtest [22:15:54]: @@@@@@@@@@@@@@@@@@@@ summary 2806s asttestmods PASS 2806s amr PASS 2817s Creating nova instance adt-noble-amd64-asterisk-20240408-212908-juju-7f2275-prod-proposed-migration-environment-2-123057e4-f667-4a03-bcf1-9dc6ceedd8ec from image adt/ubuntu-noble-amd64-server-20240408.img (UUID 30d44b2b-45a1-4839-a24b-65f68dcab139)... 2817s Creating nova instance adt-noble-amd64-asterisk-20240408-212908-juju-7f2275-prod-proposed-migration-environment-2-123057e4-f667-4a03-bcf1-9dc6ceedd8ec from image adt/ubuntu-noble-amd64-server-20240408.img (UUID 30d44b2b-45a1-4839-a24b-65f68dcab139)...