0s autopkgtest [03:06:40]: starting date and time: 2025-12-06 03:06:40+0000 0s autopkgtest [03:06:40]: git checkout: 4b346b80 nova: make wait_reboot return success even when a no-op 0s autopkgtest [03:06:40]: host juju-7f2275-prod-proposed-migration-environment-20; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.rbu_bute/out --timeout-copy=6000 --setup-commands /home/ubuntu/autopkgtest-cloud/worker-config-production/setup-canonical.sh --apt-pocket=proposed=src:python3-defaults --apt-upgrade habluetooth --timeout-short=300 --timeout-copy=20000 --timeout-build=20000 --env=ADT_TEST_TRIGGERS=python3-defaults/3.13.9-2 -- ssh -s /home/ubuntu/autopkgtest/ssh-setup/nova -- --flavor autopkgtest-cpu2-ram4-disk20-ppc64el --security-groups autopkgtest-juju-7f2275-prod-proposed-migration-environment-20@sto01-ppc64el-1.secgroup --name adt-resolute-ppc64el-habluetooth-20251206-030640-juju-7f2275-prod-proposed-migration-environment-20-5e514abb-02d3-49ee-a743-f6b9a9054132 --image adt/ubuntu-resolute-ppc64el-server --keyname testbed-juju-7f2275-prod-proposed-migration-environment-20 --net-id=net_prod-autopkgtest-workers-ppc64el -e TERM=linux --mirror=http://ftpmaster.internal/ubuntu/ 3s Creating nova instance adt-resolute-ppc64el-habluetooth-20251206-030640-juju-7f2275-prod-proposed-migration-environment-20-5e514abb-02d3-49ee-a743-f6b9a9054132 from image adt/ubuntu-resolute-ppc64el-server-20251205.img (UUID ec8e7418-51bb-4f88-80fc-4d434bdc97c2)... 54s autopkgtest [03:07:34]: testbed dpkg architecture: ppc64el 54s autopkgtest [03:07:34]: testbed apt version: 3.1.12 55s autopkgtest [03:07:35]: @@@@@@@@@@@@@@@@@@@@ test bed setup 55s autopkgtest [03:07:35]: testbed release detected to be: None 56s autopkgtest [03:07:36]: updating testbed package index (apt update) 56s Get:1 http://ftpmaster.internal/ubuntu resolute-proposed InRelease [124 kB] 56s Hit:2 http://ftpmaster.internal/ubuntu resolute InRelease 56s Hit:3 http://ftpmaster.internal/ubuntu resolute-updates InRelease 56s Hit:4 http://ftpmaster.internal/ubuntu resolute-security InRelease 56s Get:5 http://ftpmaster.internal/ubuntu resolute-proposed/main Sources [139 kB] 56s Get:6 http://ftpmaster.internal/ubuntu resolute-proposed/multiverse Sources [22.8 kB] 56s Get:7 http://ftpmaster.internal/ubuntu resolute-proposed/universe Sources [852 kB] 56s Get:8 http://ftpmaster.internal/ubuntu resolute-proposed/main ppc64el Packages [224 kB] 56s Get:9 http://ftpmaster.internal/ubuntu resolute-proposed/universe ppc64el Packages [700 kB] 57s Get:10 http://ftpmaster.internal/ubuntu resolute-proposed/multiverse ppc64el Packages [6648 B] 57s Fetched 2067 kB in 1s (2531 kB/s) 58s Reading package lists... 58s Hit:1 http://ftpmaster.internal/ubuntu resolute-proposed InRelease 58s Hit:2 http://ftpmaster.internal/ubuntu resolute InRelease 58s Hit:3 http://ftpmaster.internal/ubuntu resolute-updates InRelease 58s Hit:4 http://ftpmaster.internal/ubuntu resolute-security InRelease 59s Reading package lists... 59s Reading package lists... 59s Building dependency tree... 59s Reading state information... 59s Calculating upgrade... 60s The following packages will be upgraded: 60s libnftnl11 libpython3-stdlib lxd-installer python3 python3-attr python3-gdbm 60s python3-minimal 60s 7 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 60s Need to get 212 kB of archives. 60s After this operation, 16.4 kB of additional disk space will be used. 60s Get:1 http://ftpmaster.internal/ubuntu resolute-proposed/main ppc64el python3-minimal ppc64el 3.13.9-2 [28.1 kB] 60s Get:2 http://ftpmaster.internal/ubuntu resolute-proposed/main ppc64el python3 ppc64el 3.13.9-2 [23.0 kB] 60s Get:3 http://ftpmaster.internal/ubuntu resolute-proposed/main ppc64el libpython3-stdlib ppc64el 3.13.9-2 [10.8 kB] 60s Get:4 http://ftpmaster.internal/ubuntu resolute/main ppc64el libnftnl11 ppc64el 1.3.1-1 [80.0 kB] 60s Get:5 http://ftpmaster.internal/ubuntu resolute-proposed/main ppc64el python3-gdbm ppc64el 3.13.9-2 [11.0 kB] 60s Get:6 http://ftpmaster.internal/ubuntu resolute/main ppc64el lxd-installer all 14ubuntu0 [5428 B] 60s Get:7 http://ftpmaster.internal/ubuntu resolute/main ppc64el python3-attr all 25.4.0-1 [53.6 kB] 61s dpkg-preconfigure: unable to re-open stdin: No such file or directory 61s Fetched 212 kB in 0s (14.1 MB/s) 61s (Reading database ... (Reading database ... 5% (Reading database ... 10% (Reading database ... 15% (Reading database ... 20% (Reading database ... 25% (Reading database ... 30% (Reading database ... 35% (Reading database ... 40% (Reading database ... 45% (Reading database ... 50% (Reading database ... 55% (Reading database ... 60% (Reading database ... 65% (Reading database ... 70% (Reading database ... 75% (Reading database ... 80% (Reading database ... 85% (Reading database ... 90% (Reading database ... 95% (Reading database ... 100% (Reading database ... 81185 files and directories currently installed.) 61s Preparing to unpack .../python3-minimal_3.13.9-2_ppc64el.deb ... 61s Unpacking python3-minimal (3.13.9-2) over (3.13.7-1) ... 61s Setting up python3-minimal (3.13.9-2) ... 62s (Reading database ... (Reading database ... 5% (Reading database ... 10% (Reading database ... 15% (Reading database ... 20% (Reading database ... 25% (Reading database ... 30% (Reading database ... 35% (Reading database ... 40% (Reading database ... 45% (Reading database ... 50% (Reading database ... 55% (Reading database ... 60% (Reading database ... 65% (Reading database ... 70% (Reading database ... 75% (Reading database ... 80% (Reading database ... 85% (Reading database ... 90% (Reading database ... 95% (Reading database ... 100% (Reading database ... 81185 files and directories currently installed.) 62s Preparing to unpack .../0-python3_3.13.9-2_ppc64el.deb ... 62s running python pre-rtupdate hooks for python3.13... 62s Unpacking python3 (3.13.9-2) over (3.13.7-1) ... 62s Preparing to unpack .../1-libpython3-stdlib_3.13.9-2_ppc64el.deb ... 62s Unpacking libpython3-stdlib:ppc64el (3.13.9-2) over (3.13.7-1) ... 62s Preparing to unpack .../2-libnftnl11_1.3.1-1_ppc64el.deb ... 62s Unpacking libnftnl11:ppc64el (1.3.1-1) over (1.3.0-1) ... 62s Preparing to unpack .../3-python3-gdbm_3.13.9-2_ppc64el.deb ... 62s Unpacking python3-gdbm (3.13.9-2) over (3.13.9-1) ... 62s Preparing to unpack .../4-lxd-installer_14ubuntu0_all.deb ... 62s Unpacking lxd-installer (14ubuntu0) over (13ubuntu0) ... 63s Preparing to unpack .../5-python3-attr_25.4.0-1_all.deb ... 63s Unpacking python3-attr (25.4.0-1) over (25.3.0-1) ... 63s Setting up python3-gdbm (3.13.9-2) ... 63s Setting up libnftnl11:ppc64el (1.3.1-1) ... 63s Setting up lxd-installer (14ubuntu0) ... 63s Setting up libpython3-stdlib:ppc64el (3.13.9-2) ... 63s Setting up python3 (3.13.9-2) ... 64s running python rtupdate hooks for python3.13... 64s running python post-rtupdate hooks for python3.13... 64s Setting up python3-attr (25.4.0-1) ... 64s Processing triggers for man-db (2.13.1-1) ... 66s Processing triggers for libc-bin (2.42-2ubuntu2) ... 66s autopkgtest [03:07:46]: upgrading testbed (apt dist-upgrade and autopurge) 67s Reading package lists... 67s Building dependency tree... 67s Reading state information... 67s Calculating upgrade... 67s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 67s Reading package lists... 67s Building dependency tree... 67s Reading state information... 67s Solving dependencies... 67s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 68s autopkgtest [03:07:48]: rebooting testbed after setup commands that affected boot 106s autopkgtest [03:08:26]: testbed running kernel: Linux 6.17.0-6-generic #6-Ubuntu SMP PREEMPT_DYNAMIC Tue Oct 7 13:47:32 UTC 2025 109s autopkgtest [03:08:29]: @@@@@@@@@@@@@@@@@@@@ apt-source habluetooth 110s Get:1 http://ftpmaster.internal/ubuntu resolute/universe habluetooth 4.0.1-1 (dsc) [2584 B] 110s Get:2 http://ftpmaster.internal/ubuntu resolute/universe habluetooth 4.0.1-1 (tar) [133 kB] 110s Get:3 http://ftpmaster.internal/ubuntu resolute/universe habluetooth 4.0.1-1 (diff) [4508 B] 111s gpgv: Signature made Mon Jul 7 19:49:22 2025 UTC 111s gpgv: using RSA key FB8ACFA78C726089C38AD0269605A1098C63B92A 111s gpgv: Can't check signature: No public key 111s dpkg-source: warning: cannot verify inline signature for ./habluetooth_4.0.1-1.dsc: no acceptable signature found 111s autopkgtest [03:08:31]: testing package habluetooth version 4.0.1-1 111s autopkgtest [03:08:31]: build not needed 111s autopkgtest [03:08:31]: test pybuild-autopkgtest: preparing testbed 111s Reading package lists... 112s Building dependency tree... 112s Reading state information... 112s Solving dependencies... 112s The following NEW packages will be installed: 112s autoconf automake autopoint autotools-dev bluez build-essential cpp cpp-15 112s cpp-15-powerpc64le-linux-gnu cpp-powerpc64le-linux-gnu debhelper debugedit 112s dh-autoreconf dh-python dh-strip-nondeterminism docutils-common dwz 112s fonts-font-awesome fonts-lato furo g++ g++-15 g++-15-powerpc64le-linux-gnu 112s g++-powerpc64le-linux-gnu gcc gcc-15 gcc-15-powerpc64le-linux-gnu 112s gcc-powerpc64le-linux-gnu gettext intltool-debian libarchive-zip-perl 112s libasan8 libasound2-data libasound2t64 libcc1-0 libdebhelper-perl 112s libfile-stripnondeterminism-perl libgcc-15-dev libgomp1 libisl23 libitm1 112s libjs-jquery libjs-jquery-hotkeys libjs-jquery-isonscreen 112s libjs-jquery-metadata libjs-jquery-tablesorter 112s libjs-jquery-throttle-debounce libjs-sphinxdoc libjs-underscore libjson-perl 112s liblsan0 libmpc3 libpython3.14-minimal libpython3.14-stdlib libquadmath0 112s libstdc++-15-dev libtool libtsan2 libubsan1 m4 po-debconf 112s pybuild-plugin-autopkgtest pybuild-plugin-pyproject 112s python3-accessible-pygments python3-aiooui python3-alabaster python3-all 112s python3-async-generator python3-async-interrupt python3-bleak 112s python3-bleak-retry-connector python3-bluetooth-adapters 112s python3-bluetooth-auto-recovery python3-bluetooth-data-tools python3-bs4 112s python3-btsocket python3-build python3-coverage python3-dbus-fast 112s python3-defusedxml python3-docutils python3-freezegun python3-habluetooth 112s python3-imagesize python3-iniconfig python3-installer 112s python3-mdit-py-plugins python3-myst-parser python3-pluggy 112s python3-poetry-core python3-pyproject-hooks python3-pyric python3-pytest 112s python3-pytest-asyncio python3-pytest-cov python3-roman 112s python3-roman-numerals python3-snowballstemmer python3-soupsieve 112s python3-sphinx python3-uart-devices python3-usb-devices python3-wheel 112s python3.14 python3.14-minimal sgml-base sphinx-basic-ng sphinx-common 112s sphinx-rtd-theme-common xml-core 112s 0 upgraded, 110 newly installed, 0 to remove and 0 not upgraded. 112s Need to get 86.1 MB of archives. 112s After this operation, 318 MB of additional disk space will be used. 112s Get:1 http://ftpmaster.internal/ubuntu resolute/main ppc64el fonts-lato all 2.015-1build1 [2779 kB] 113s Get:2 http://ftpmaster.internal/ubuntu resolute/main ppc64el libpython3.14-minimal ppc64el 3.14.0-4 [908 kB] 113s Get:3 http://ftpmaster.internal/ubuntu resolute/main ppc64el python3.14-minimal ppc64el 3.14.0-4 [2705 kB] 113s Get:4 http://ftpmaster.internal/ubuntu resolute/main ppc64el m4 ppc64el 1.4.20-2 [236 kB] 113s Get:5 http://ftpmaster.internal/ubuntu resolute/main ppc64el autoconf all 2.72-3.1ubuntu1 [384 kB] 113s Get:6 http://ftpmaster.internal/ubuntu resolute/main ppc64el autotools-dev all 20240727.1 [43.4 kB] 113s Get:7 http://ftpmaster.internal/ubuntu resolute/main ppc64el automake all 1:1.18.1-3 [582 kB] 113s Get:8 http://ftpmaster.internal/ubuntu resolute/main ppc64el autopoint all 0.23.2-1 [620 kB] 113s Get:9 http://ftpmaster.internal/ubuntu resolute/main ppc64el libasound2-data all 1.2.14-2ubuntu1 [21.3 kB] 113s Get:10 http://ftpmaster.internal/ubuntu resolute/main ppc64el libasound2t64 ppc64el 1.2.14-2ubuntu1 [507 kB] 113s Get:11 http://ftpmaster.internal/ubuntu resolute/main ppc64el bluez ppc64el 5.84-1 [1805 kB] 113s Get:12 http://ftpmaster.internal/ubuntu resolute/main ppc64el libisl23 ppc64el 0.27-1 [882 kB] 113s Get:13 http://ftpmaster.internal/ubuntu resolute/main ppc64el libmpc3 ppc64el 1.3.1-2 [62.5 kB] 113s Get:14 http://ftpmaster.internal/ubuntu resolute/main ppc64el cpp-15-powerpc64le-linux-gnu ppc64el 15.2.0-9ubuntu1 [11.4 MB] 113s Get:15 http://ftpmaster.internal/ubuntu resolute/main ppc64el cpp-15 ppc64el 15.2.0-9ubuntu1 [1034 B] 113s Get:16 http://ftpmaster.internal/ubuntu resolute/main ppc64el cpp-powerpc64le-linux-gnu ppc64el 4:15.2.0-4ubuntu1 [5746 B] 113s Get:17 http://ftpmaster.internal/ubuntu resolute/main ppc64el cpp ppc64el 4:15.2.0-4ubuntu1 [22.4 kB] 113s Get:18 http://ftpmaster.internal/ubuntu resolute/main ppc64el libcc1-0 ppc64el 15.2.0-9ubuntu1 [49.0 kB] 113s Get:19 http://ftpmaster.internal/ubuntu resolute/main ppc64el libgomp1 ppc64el 15.2.0-9ubuntu1 [169 kB] 113s Get:20 http://ftpmaster.internal/ubuntu resolute/main ppc64el libitm1 ppc64el 15.2.0-9ubuntu1 [32.3 kB] 113s Get:21 http://ftpmaster.internal/ubuntu resolute/main ppc64el libasan8 ppc64el 15.2.0-9ubuntu1 [3006 kB] 113s Get:22 http://ftpmaster.internal/ubuntu resolute/main ppc64el liblsan0 ppc64el 15.2.0-9ubuntu1 [1374 kB] 113s Get:23 http://ftpmaster.internal/ubuntu resolute/main ppc64el libtsan2 ppc64el 15.2.0-9ubuntu1 [2729 kB] 113s Get:24 http://ftpmaster.internal/ubuntu resolute/main ppc64el libubsan1 ppc64el 15.2.0-9ubuntu1 [1231 kB] 113s Get:25 http://ftpmaster.internal/ubuntu resolute/main ppc64el libquadmath0 ppc64el 15.2.0-9ubuntu1 [160 kB] 113s Get:26 http://ftpmaster.internal/ubuntu resolute/main ppc64el libgcc-15-dev ppc64el 15.2.0-9ubuntu1 [1670 kB] 113s Get:27 http://ftpmaster.internal/ubuntu resolute/main ppc64el gcc-15-powerpc64le-linux-gnu ppc64el 15.2.0-9ubuntu1 [22.4 MB] 114s Get:28 http://ftpmaster.internal/ubuntu resolute/main ppc64el gcc-15 ppc64el 15.2.0-9ubuntu1 [527 kB] 114s Get:29 http://ftpmaster.internal/ubuntu resolute/main ppc64el gcc-powerpc64le-linux-gnu ppc64el 4:15.2.0-4ubuntu1 [1220 B] 114s Get:30 http://ftpmaster.internal/ubuntu resolute/main ppc64el gcc ppc64el 4:15.2.0-4ubuntu1 [5032 B] 114s Get:31 http://ftpmaster.internal/ubuntu resolute/main ppc64el libstdc++-15-dev ppc64el 15.2.0-9ubuntu1 [2745 kB] 114s Get:32 http://ftpmaster.internal/ubuntu resolute/main ppc64el g++-15-powerpc64le-linux-gnu ppc64el 15.2.0-9ubuntu1 [13.0 MB] 114s Get:33 http://ftpmaster.internal/ubuntu resolute/main ppc64el g++-15 ppc64el 15.2.0-9ubuntu1 [24.3 kB] 114s Get:34 http://ftpmaster.internal/ubuntu resolute/main ppc64el g++-powerpc64le-linux-gnu ppc64el 4:15.2.0-4ubuntu1 [970 B] 114s Get:35 http://ftpmaster.internal/ubuntu resolute/main ppc64el g++ ppc64el 4:15.2.0-4ubuntu1 [1092 B] 114s Get:36 http://ftpmaster.internal/ubuntu resolute/main ppc64el build-essential ppc64el 12.12ubuntu2 [5256 B] 114s Get:37 http://ftpmaster.internal/ubuntu resolute/main ppc64el libdebhelper-perl all 13.24.2ubuntu1 [95.7 kB] 114s Get:38 http://ftpmaster.internal/ubuntu resolute/main ppc64el libtool all 2.5.4-7 [169 kB] 114s Get:39 http://ftpmaster.internal/ubuntu resolute/main ppc64el dh-autoreconf all 21 [12.5 kB] 114s Get:40 http://ftpmaster.internal/ubuntu resolute/main ppc64el libarchive-zip-perl all 1.68-1 [90.2 kB] 114s Get:41 http://ftpmaster.internal/ubuntu resolute/main ppc64el libfile-stripnondeterminism-perl all 1.15.0-1 [20.5 kB] 114s Get:42 http://ftpmaster.internal/ubuntu resolute/main ppc64el dh-strip-nondeterminism all 1.15.0-1 [5090 B] 114s Get:43 http://ftpmaster.internal/ubuntu resolute/main ppc64el debugedit ppc64el 1:5.2-3 [57.3 kB] 114s Get:44 http://ftpmaster.internal/ubuntu resolute/main ppc64el dwz ppc64el 0.16-2 [142 kB] 114s Get:45 http://ftpmaster.internal/ubuntu resolute/main ppc64el gettext ppc64el 0.23.2-1 [1177 kB] 114s Get:46 http://ftpmaster.internal/ubuntu resolute/main ppc64el intltool-debian all 0.35.0+20060710.6build1 [24.1 kB] 114s Get:47 http://ftpmaster.internal/ubuntu resolute/main ppc64el po-debconf all 1.0.21+nmu1 [233 kB] 114s Get:48 http://ftpmaster.internal/ubuntu resolute/main ppc64el debhelper all 13.24.2ubuntu1 [896 kB] 114s Get:49 http://ftpmaster.internal/ubuntu resolute/universe ppc64el dh-python all 6.20251029 [120 kB] 114s Get:50 http://ftpmaster.internal/ubuntu resolute/main ppc64el sgml-base all 1.31+nmu1 [11.0 kB] 114s Get:51 http://ftpmaster.internal/ubuntu resolute/main ppc64el xml-core all 0.19 [20.3 kB] 114s Get:52 http://ftpmaster.internal/ubuntu resolute/main ppc64el docutils-common all 0.22.3+dfsg-1 [130 kB] 114s Get:53 http://ftpmaster.internal/ubuntu resolute/main ppc64el fonts-font-awesome all 5.0.10+really4.7.0~dfsg-4.1build1 [531 kB] 114s Get:54 http://ftpmaster.internal/ubuntu resolute/universe ppc64el python3-accessible-pygments all 0.0.5-2 [790 kB] 114s Get:55 http://ftpmaster.internal/ubuntu resolute/main ppc64el python3-soupsieve all 2.7-2 [33.6 kB] 114s Get:56 http://ftpmaster.internal/ubuntu resolute/main ppc64el python3-bs4 all 4.14.2-1 [82.8 kB] 114s Get:57 http://ftpmaster.internal/ubuntu resolute/main ppc64el python3-defusedxml all 0.7.1-3 [42.2 kB] 114s Get:58 http://ftpmaster.internal/ubuntu resolute/main ppc64el libjs-jquery all 3.7.1+dfsg+~3.5.33-1build1 [321 kB] 114s Get:59 http://ftpmaster.internal/ubuntu resolute/main ppc64el libjs-underscore all 1.13.4~dfsg+~1.11.4-3 [118 kB] 114s Get:60 http://ftpmaster.internal/ubuntu resolute/main ppc64el libjs-sphinxdoc all 8.2.3-1ubuntu2 [28.0 kB] 114s Get:61 http://ftpmaster.internal/ubuntu resolute/main ppc64el libjson-perl all 4.10000-1 [81.9 kB] 114s Get:62 http://ftpmaster.internal/ubuntu resolute/main ppc64el sphinx-common all 8.2.3-1ubuntu2 [656 kB] 114s Get:63 http://ftpmaster.internal/ubuntu resolute/main ppc64el python3-alabaster all 0.7.16-0.1 [18.5 kB] 114s Get:64 http://ftpmaster.internal/ubuntu resolute/main ppc64el python3-roman-numerals all 3.1.0-2 [8470 B] 114s Get:65 http://ftpmaster.internal/ubuntu resolute/main ppc64el python3-docutils all 0.22.3+dfsg-1 [438 kB] 114s Get:66 http://ftpmaster.internal/ubuntu resolute/main ppc64el python3-imagesize all 1.4.1-1build1 [6900 B] 114s Get:67 http://ftpmaster.internal/ubuntu resolute/main ppc64el python3-roman all 5.2-1 [10.8 kB] 114s Get:68 http://ftpmaster.internal/ubuntu resolute/main ppc64el python3-snowballstemmer all 3.0.1-1 [65.9 kB] 114s Get:69 http://ftpmaster.internal/ubuntu resolute/main ppc64el python3-sphinx all 8.2.3-1ubuntu2 [482 kB] 114s Get:70 http://ftpmaster.internal/ubuntu resolute/universe ppc64el sphinx-basic-ng all 1.0.0~beta2-1 [12.0 kB] 114s Get:71 http://ftpmaster.internal/ubuntu resolute/universe ppc64el furo all 2025.09.25+dfsg-2 [53.7 kB] 114s Get:72 http://ftpmaster.internal/ubuntu resolute/universe ppc64el libjs-jquery-metadata all 12-4 [6582 B] 114s Get:73 http://ftpmaster.internal/ubuntu resolute/universe ppc64el libjs-jquery-tablesorter all 1:2.31.3+dfsg1-4 [192 kB] 114s Get:74 http://ftpmaster.internal/ubuntu resolute/universe ppc64el libjs-jquery-throttle-debounce all 1.1+dfsg.1-2 [12.5 kB] 114s Get:75 http://ftpmaster.internal/ubuntu resolute/main ppc64el libpython3.14-stdlib ppc64el 3.14.0-4 [2446 kB] 114s Get:76 http://ftpmaster.internal/ubuntu resolute/universe ppc64el pybuild-plugin-autopkgtest all 6.20251029 [1746 B] 114s Get:77 http://ftpmaster.internal/ubuntu resolute/universe ppc64el python3-pyproject-hooks all 1.2.0-1 [10.2 kB] 114s Get:78 http://ftpmaster.internal/ubuntu resolute/universe ppc64el python3-wheel all 0.46.1-2 [22.1 kB] 114s Get:79 http://ftpmaster.internal/ubuntu resolute/universe ppc64el python3-build all 1.2.2-4 [31.0 kB] 114s Get:80 http://ftpmaster.internal/ubuntu resolute/universe ppc64el python3-installer all 0.7.0+dfsg1-3 [17.4 kB] 114s Get:81 http://ftpmaster.internal/ubuntu resolute/universe ppc64el pybuild-plugin-pyproject all 6.20251029 [1732 B] 114s Get:82 http://ftpmaster.internal/ubuntu resolute/universe ppc64el python3-aiooui all 0.1.9-1 [312 kB] 114s Get:83 http://ftpmaster.internal/ubuntu resolute/main ppc64el python3.14 ppc64el 3.14.0-4 [805 kB] 114s Get:84 http://ftpmaster.internal/ubuntu resolute-proposed/main ppc64el python3-all ppc64el 3.13.9-2 [890 B] 114s Get:85 http://ftpmaster.internal/ubuntu resolute/universe ppc64el python3-async-generator all 1.10-7 [18.1 kB] 114s Get:86 http://ftpmaster.internal/ubuntu resolute/universe ppc64el python3-async-interrupt all 1.2.2-1 [6604 B] 114s Get:87 http://ftpmaster.internal/ubuntu resolute/universe ppc64el python3-dbus-fast ppc64el 3.1.2-1 [981 kB] 114s Get:88 http://ftpmaster.internal/ubuntu resolute/universe ppc64el python3-bleak all 1.1.1-1 [95.0 kB] 114s Get:89 http://ftpmaster.internal/ubuntu resolute/universe ppc64el python3-uart-devices all 0.1.1-1 [6742 B] 114s Get:90 http://ftpmaster.internal/ubuntu resolute/universe ppc64el python3-usb-devices all 0.4.5-2 [9014 B] 114s Get:91 http://ftpmaster.internal/ubuntu resolute/universe ppc64el python3-bluetooth-adapters all 2.1.1-1 [13.7 kB] 114s Get:92 http://ftpmaster.internal/ubuntu resolute/universe ppc64el python3-bleak-retry-connector all 4.4.4-1 [20.1 kB] 114s Get:93 http://ftpmaster.internal/ubuntu resolute/universe ppc64el python3-btsocket all 0.3.0-1 [19.0 kB] 114s Get:94 http://ftpmaster.internal/ubuntu resolute/universe ppc64el python3-pyric all 0.1.6.4+git20170421.0562b17-1 [114 kB] 114s Get:95 http://ftpmaster.internal/ubuntu resolute/main ppc64el sphinx-rtd-theme-common all 3.0.2+dfsg-3 [1013 kB] 114s Get:96 http://ftpmaster.internal/ubuntu resolute/universe ppc64el python3-bluetooth-auto-recovery all 1.5.3-1 [29.4 kB] 114s Get:97 http://ftpmaster.internal/ubuntu resolute/universe ppc64el python3-bluetooth-data-tools ppc64el 1.28.4-1 [11.7 kB] 114s Get:98 http://ftpmaster.internal/ubuntu resolute/universe ppc64el python3-coverage ppc64el 7.8.2+dfsg1-1 [158 kB] 114s Get:99 http://ftpmaster.internal/ubuntu resolute/universe ppc64el python3-freezegun all 1.5.1-1.2 [15.9 kB] 114s Get:100 http://ftpmaster.internal/ubuntu resolute/universe ppc64el python3-habluetooth ppc64el 4.0.1-1 [65.3 kB] 114s Get:101 http://ftpmaster.internal/ubuntu resolute/universe ppc64el python3-iniconfig all 2.1.0-1 [6840 B] 114s Get:102 http://ftpmaster.internal/ubuntu resolute/universe ppc64el python3-mdit-py-plugins all 0.5.0-1 [31.5 kB] 115s Get:103 http://ftpmaster.internal/ubuntu resolute/universe ppc64el python3-myst-parser all 4.0.1-1 [64.9 kB] 115s Get:104 http://ftpmaster.internal/ubuntu resolute/universe ppc64el python3-pluggy all 1.6.0-1 [21.0 kB] 115s Get:105 http://ftpmaster.internal/ubuntu resolute/universe ppc64el python3-poetry-core all 2.2.1-2 [226 kB] 115s Get:106 http://ftpmaster.internal/ubuntu resolute/universe ppc64el python3-pytest all 8.3.5-2 [252 kB] 115s Get:107 http://ftpmaster.internal/ubuntu resolute/universe ppc64el python3-pytest-asyncio all 0.25.1-1 [17.0 kB] 115s Get:108 http://ftpmaster.internal/ubuntu resolute/universe ppc64el libjs-jquery-hotkeys all 0.2.0-1 [13.3 kB] 115s Get:109 http://ftpmaster.internal/ubuntu resolute/universe ppc64el libjs-jquery-isonscreen all 1.2.0-2 [3814 B] 115s Get:110 http://ftpmaster.internal/ubuntu resolute/universe ppc64el python3-pytest-cov all 5.0.0-1 [21.3 kB] 115s Fetched 86.1 MB in 3s (34.4 MB/s) 115s Selecting previously unselected package fonts-lato. 115s (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 ... 81185 files and directories currently installed.) 115s Preparing to unpack .../000-fonts-lato_2.015-1build1_all.deb ... 115s Unpacking fonts-lato (2.015-1build1) ... 115s Selecting previously unselected package libpython3.14-minimal:ppc64el. 115s Preparing to unpack .../001-libpython3.14-minimal_3.14.0-4_ppc64el.deb ... 115s Unpacking libpython3.14-minimal:ppc64el (3.14.0-4) ... 116s Selecting previously unselected package python3.14-minimal. 116s Preparing to unpack .../002-python3.14-minimal_3.14.0-4_ppc64el.deb ... 116s Unpacking python3.14-minimal (3.14.0-4) ... 116s Selecting previously unselected package m4. 116s Preparing to unpack .../003-m4_1.4.20-2_ppc64el.deb ... 116s Unpacking m4 (1.4.20-2) ... 116s Selecting previously unselected package autoconf. 116s Preparing to unpack .../004-autoconf_2.72-3.1ubuntu1_all.deb ... 116s Unpacking autoconf (2.72-3.1ubuntu1) ... 116s Selecting previously unselected package autotools-dev. 116s Preparing to unpack .../005-autotools-dev_20240727.1_all.deb ... 116s Unpacking autotools-dev (20240727.1) ... 116s Selecting previously unselected package automake. 116s Preparing to unpack .../006-automake_1%3a1.18.1-3_all.deb ... 116s Unpacking automake (1:1.18.1-3) ... 116s Selecting previously unselected package autopoint. 116s Preparing to unpack .../007-autopoint_0.23.2-1_all.deb ... 116s Unpacking autopoint (0.23.2-1) ... 116s Selecting previously unselected package libasound2-data. 116s Preparing to unpack .../008-libasound2-data_1.2.14-2ubuntu1_all.deb ... 116s Unpacking libasound2-data (1.2.14-2ubuntu1) ... 116s Selecting previously unselected package libasound2t64:ppc64el. 116s Preparing to unpack .../009-libasound2t64_1.2.14-2ubuntu1_ppc64el.deb ... 116s Unpacking libasound2t64:ppc64el (1.2.14-2ubuntu1) ... 116s Selecting previously unselected package bluez. 116s Preparing to unpack .../010-bluez_5.84-1_ppc64el.deb ... 116s Unpacking bluez (5.84-1) ... 116s Selecting previously unselected package libisl23:ppc64el. 116s Preparing to unpack .../011-libisl23_0.27-1_ppc64el.deb ... 116s Unpacking libisl23:ppc64el (0.27-1) ... 116s Selecting previously unselected package libmpc3:ppc64el. 116s Preparing to unpack .../012-libmpc3_1.3.1-2_ppc64el.deb ... 116s Unpacking libmpc3:ppc64el (1.3.1-2) ... 116s Selecting previously unselected package cpp-15-powerpc64le-linux-gnu. 116s Preparing to unpack .../013-cpp-15-powerpc64le-linux-gnu_15.2.0-9ubuntu1_ppc64el.deb ... 116s Unpacking cpp-15-powerpc64le-linux-gnu (15.2.0-9ubuntu1) ... 116s Selecting previously unselected package cpp-15. 116s Preparing to unpack .../014-cpp-15_15.2.0-9ubuntu1_ppc64el.deb ... 116s Unpacking cpp-15 (15.2.0-9ubuntu1) ... 116s Selecting previously unselected package cpp-powerpc64le-linux-gnu. 116s Preparing to unpack .../015-cpp-powerpc64le-linux-gnu_4%3a15.2.0-4ubuntu1_ppc64el.deb ... 116s Unpacking cpp-powerpc64le-linux-gnu (4:15.2.0-4ubuntu1) ... 116s Selecting previously unselected package cpp. 116s Preparing to unpack .../016-cpp_4%3a15.2.0-4ubuntu1_ppc64el.deb ... 116s Unpacking cpp (4:15.2.0-4ubuntu1) ... 116s Selecting previously unselected package libcc1-0:ppc64el. 116s Preparing to unpack .../017-libcc1-0_15.2.0-9ubuntu1_ppc64el.deb ... 116s Unpacking libcc1-0:ppc64el (15.2.0-9ubuntu1) ... 116s Selecting previously unselected package libgomp1:ppc64el. 116s Preparing to unpack .../018-libgomp1_15.2.0-9ubuntu1_ppc64el.deb ... 116s Unpacking libgomp1:ppc64el (15.2.0-9ubuntu1) ... 116s Selecting previously unselected package libitm1:ppc64el. 116s Preparing to unpack .../019-libitm1_15.2.0-9ubuntu1_ppc64el.deb ... 116s Unpacking libitm1:ppc64el (15.2.0-9ubuntu1) ... 116s Selecting previously unselected package libasan8:ppc64el. 116s Preparing to unpack .../020-libasan8_15.2.0-9ubuntu1_ppc64el.deb ... 116s Unpacking libasan8:ppc64el (15.2.0-9ubuntu1) ... 116s Selecting previously unselected package liblsan0:ppc64el. 116s Preparing to unpack .../021-liblsan0_15.2.0-9ubuntu1_ppc64el.deb ... 116s Unpacking liblsan0:ppc64el (15.2.0-9ubuntu1) ... 116s Selecting previously unselected package libtsan2:ppc64el. 116s Preparing to unpack .../022-libtsan2_15.2.0-9ubuntu1_ppc64el.deb ... 116s Unpacking libtsan2:ppc64el (15.2.0-9ubuntu1) ... 116s Selecting previously unselected package libubsan1:ppc64el. 116s Preparing to unpack .../023-libubsan1_15.2.0-9ubuntu1_ppc64el.deb ... 116s Unpacking libubsan1:ppc64el (15.2.0-9ubuntu1) ... 116s Selecting previously unselected package libquadmath0:ppc64el. 116s Preparing to unpack .../024-libquadmath0_15.2.0-9ubuntu1_ppc64el.deb ... 116s Unpacking libquadmath0:ppc64el (15.2.0-9ubuntu1) ... 116s Selecting previously unselected package libgcc-15-dev:ppc64el. 116s Preparing to unpack .../025-libgcc-15-dev_15.2.0-9ubuntu1_ppc64el.deb ... 116s Unpacking libgcc-15-dev:ppc64el (15.2.0-9ubuntu1) ... 116s Selecting previously unselected package gcc-15-powerpc64le-linux-gnu. 116s Preparing to unpack .../026-gcc-15-powerpc64le-linux-gnu_15.2.0-9ubuntu1_ppc64el.deb ... 116s Unpacking gcc-15-powerpc64le-linux-gnu (15.2.0-9ubuntu1) ... 117s Selecting previously unselected package gcc-15. 117s Preparing to unpack .../027-gcc-15_15.2.0-9ubuntu1_ppc64el.deb ... 117s Unpacking gcc-15 (15.2.0-9ubuntu1) ... 117s Selecting previously unselected package gcc-powerpc64le-linux-gnu. 117s Preparing to unpack .../028-gcc-powerpc64le-linux-gnu_4%3a15.2.0-4ubuntu1_ppc64el.deb ... 117s Unpacking gcc-powerpc64le-linux-gnu (4:15.2.0-4ubuntu1) ... 117s Selecting previously unselected package gcc. 117s Preparing to unpack .../029-gcc_4%3a15.2.0-4ubuntu1_ppc64el.deb ... 117s Unpacking gcc (4:15.2.0-4ubuntu1) ... 117s Selecting previously unselected package libstdc++-15-dev:ppc64el. 117s Preparing to unpack .../030-libstdc++-15-dev_15.2.0-9ubuntu1_ppc64el.deb ... 117s Unpacking libstdc++-15-dev:ppc64el (15.2.0-9ubuntu1) ... 117s Selecting previously unselected package g++-15-powerpc64le-linux-gnu. 117s Preparing to unpack .../031-g++-15-powerpc64le-linux-gnu_15.2.0-9ubuntu1_ppc64el.deb ... 117s Unpacking g++-15-powerpc64le-linux-gnu (15.2.0-9ubuntu1) ... 117s Selecting previously unselected package g++-15. 117s Preparing to unpack .../032-g++-15_15.2.0-9ubuntu1_ppc64el.deb ... 117s Unpacking g++-15 (15.2.0-9ubuntu1) ... 117s Selecting previously unselected package g++-powerpc64le-linux-gnu. 117s Preparing to unpack .../033-g++-powerpc64le-linux-gnu_4%3a15.2.0-4ubuntu1_ppc64el.deb ... 117s Unpacking g++-powerpc64le-linux-gnu (4:15.2.0-4ubuntu1) ... 117s Selecting previously unselected package g++. 117s Preparing to unpack .../034-g++_4%3a15.2.0-4ubuntu1_ppc64el.deb ... 117s Unpacking g++ (4:15.2.0-4ubuntu1) ... 117s Selecting previously unselected package build-essential. 117s Preparing to unpack .../035-build-essential_12.12ubuntu2_ppc64el.deb ... 117s Unpacking build-essential (12.12ubuntu2) ... 117s Selecting previously unselected package libdebhelper-perl. 117s Preparing to unpack .../036-libdebhelper-perl_13.24.2ubuntu1_all.deb ... 117s Unpacking libdebhelper-perl (13.24.2ubuntu1) ... 117s Selecting previously unselected package libtool. 117s Preparing to unpack .../037-libtool_2.5.4-7_all.deb ... 117s Unpacking libtool (2.5.4-7) ... 117s Selecting previously unselected package dh-autoreconf. 117s Preparing to unpack .../038-dh-autoreconf_21_all.deb ... 117s Unpacking dh-autoreconf (21) ... 117s Selecting previously unselected package libarchive-zip-perl. 117s Preparing to unpack .../039-libarchive-zip-perl_1.68-1_all.deb ... 117s Unpacking libarchive-zip-perl (1.68-1) ... 117s Selecting previously unselected package libfile-stripnondeterminism-perl. 117s Preparing to unpack .../040-libfile-stripnondeterminism-perl_1.15.0-1_all.deb ... 117s Unpacking libfile-stripnondeterminism-perl (1.15.0-1) ... 117s Selecting previously unselected package dh-strip-nondeterminism. 117s Preparing to unpack .../041-dh-strip-nondeterminism_1.15.0-1_all.deb ... 117s Unpacking dh-strip-nondeterminism (1.15.0-1) ... 117s Selecting previously unselected package debugedit. 117s Preparing to unpack .../042-debugedit_1%3a5.2-3_ppc64el.deb ... 117s Unpacking debugedit (1:5.2-3) ... 117s Selecting previously unselected package dwz. 117s Preparing to unpack .../043-dwz_0.16-2_ppc64el.deb ... 117s Unpacking dwz (0.16-2) ... 117s Selecting previously unselected package gettext. 117s Preparing to unpack .../044-gettext_0.23.2-1_ppc64el.deb ... 117s Unpacking gettext (0.23.2-1) ... 117s Selecting previously unselected package intltool-debian. 117s Preparing to unpack .../045-intltool-debian_0.35.0+20060710.6build1_all.deb ... 117s Unpacking intltool-debian (0.35.0+20060710.6build1) ... 117s Selecting previously unselected package po-debconf. 117s Preparing to unpack .../046-po-debconf_1.0.21+nmu1_all.deb ... 117s Unpacking po-debconf (1.0.21+nmu1) ... 118s Selecting previously unselected package debhelper. 118s Preparing to unpack .../047-debhelper_13.24.2ubuntu1_all.deb ... 118s Unpacking debhelper (13.24.2ubuntu1) ... 118s Selecting previously unselected package dh-python. 118s Preparing to unpack .../048-dh-python_6.20251029_all.deb ... 118s Unpacking dh-python (6.20251029) ... 118s Selecting previously unselected package sgml-base. 118s Preparing to unpack .../049-sgml-base_1.31+nmu1_all.deb ... 118s Unpacking sgml-base (1.31+nmu1) ... 118s Selecting previously unselected package xml-core. 118s Preparing to unpack .../050-xml-core_0.19_all.deb ... 118s Unpacking xml-core (0.19) ... 118s Selecting previously unselected package docutils-common. 118s Preparing to unpack .../051-docutils-common_0.22.3+dfsg-1_all.deb ... 118s Unpacking docutils-common (0.22.3+dfsg-1) ... 118s Selecting previously unselected package fonts-font-awesome. 118s Preparing to unpack .../052-fonts-font-awesome_5.0.10+really4.7.0~dfsg-4.1build1_all.deb ... 118s Unpacking fonts-font-awesome (5.0.10+really4.7.0~dfsg-4.1build1) ... 118s Selecting previously unselected package python3-accessible-pygments. 118s Preparing to unpack .../053-python3-accessible-pygments_0.0.5-2_all.deb ... 118s Unpacking python3-accessible-pygments (0.0.5-2) ... 118s Selecting previously unselected package python3-soupsieve. 118s Preparing to unpack .../054-python3-soupsieve_2.7-2_all.deb ... 118s Unpacking python3-soupsieve (2.7-2) ... 118s Selecting previously unselected package python3-bs4. 118s Preparing to unpack .../055-python3-bs4_4.14.2-1_all.deb ... 118s Unpacking python3-bs4 (4.14.2-1) ... 118s Selecting previously unselected package python3-defusedxml. 118s Preparing to unpack .../056-python3-defusedxml_0.7.1-3_all.deb ... 118s Unpacking python3-defusedxml (0.7.1-3) ... 118s Selecting previously unselected package libjs-jquery. 118s Preparing to unpack .../057-libjs-jquery_3.7.1+dfsg+~3.5.33-1build1_all.deb ... 118s Unpacking libjs-jquery (3.7.1+dfsg+~3.5.33-1build1) ... 118s Selecting previously unselected package libjs-underscore. 118s Preparing to unpack .../058-libjs-underscore_1.13.4~dfsg+~1.11.4-3_all.deb ... 118s Unpacking libjs-underscore (1.13.4~dfsg+~1.11.4-3) ... 118s Selecting previously unselected package libjs-sphinxdoc. 118s Preparing to unpack .../059-libjs-sphinxdoc_8.2.3-1ubuntu2_all.deb ... 118s Unpacking libjs-sphinxdoc (8.2.3-1ubuntu2) ... 118s Selecting previously unselected package libjson-perl. 118s Preparing to unpack .../060-libjson-perl_4.10000-1_all.deb ... 118s Unpacking libjson-perl (4.10000-1) ... 118s Selecting previously unselected package sphinx-common. 118s Preparing to unpack .../061-sphinx-common_8.2.3-1ubuntu2_all.deb ... 118s Unpacking sphinx-common (8.2.3-1ubuntu2) ... 118s Selecting previously unselected package python3-alabaster. 118s Preparing to unpack .../062-python3-alabaster_0.7.16-0.1_all.deb ... 118s Unpacking python3-alabaster (0.7.16-0.1) ... 118s Selecting previously unselected package python3-roman-numerals. 118s Preparing to unpack .../063-python3-roman-numerals_3.1.0-2_all.deb ... 118s Unpacking python3-roman-numerals (3.1.0-2) ... 118s Selecting previously unselected package python3-docutils. 118s Preparing to unpack .../064-python3-docutils_0.22.3+dfsg-1_all.deb ... 118s Unpacking python3-docutils (0.22.3+dfsg-1) ... 118s Selecting previously unselected package python3-imagesize. 118s Preparing to unpack .../065-python3-imagesize_1.4.1-1build1_all.deb ... 118s Unpacking python3-imagesize (1.4.1-1build1) ... 118s Selecting previously unselected package python3-roman. 118s Preparing to unpack .../066-python3-roman_5.2-1_all.deb ... 118s Unpacking python3-roman (5.2-1) ... 118s Selecting previously unselected package python3-snowballstemmer. 118s Preparing to unpack .../067-python3-snowballstemmer_3.0.1-1_all.deb ... 118s Unpacking python3-snowballstemmer (3.0.1-1) ... 118s Selecting previously unselected package python3-sphinx. 118s Preparing to unpack .../068-python3-sphinx_8.2.3-1ubuntu2_all.deb ... 118s Unpacking python3-sphinx (8.2.3-1ubuntu2) ... 118s Selecting previously unselected package sphinx-basic-ng. 118s Preparing to unpack .../069-sphinx-basic-ng_1.0.0~beta2-1_all.deb ... 118s Unpacking sphinx-basic-ng (1.0.0~beta2-1) ... 118s Selecting previously unselected package furo. 118s Preparing to unpack .../070-furo_2025.09.25+dfsg-2_all.deb ... 118s Unpacking furo (2025.09.25+dfsg-2) ... 118s Selecting previously unselected package libjs-jquery-metadata. 118s Preparing to unpack .../071-libjs-jquery-metadata_12-4_all.deb ... 118s Unpacking libjs-jquery-metadata (12-4) ... 118s Selecting previously unselected package libjs-jquery-tablesorter. 118s Preparing to unpack .../072-libjs-jquery-tablesorter_1%3a2.31.3+dfsg1-4_all.deb ... 118s Unpacking libjs-jquery-tablesorter (1:2.31.3+dfsg1-4) ... 119s Selecting previously unselected package libjs-jquery-throttle-debounce. 119s Preparing to unpack .../073-libjs-jquery-throttle-debounce_1.1+dfsg.1-2_all.deb ... 119s Unpacking libjs-jquery-throttle-debounce (1.1+dfsg.1-2) ... 119s Selecting previously unselected package libpython3.14-stdlib:ppc64el. 119s Preparing to unpack .../074-libpython3.14-stdlib_3.14.0-4_ppc64el.deb ... 119s Unpacking libpython3.14-stdlib:ppc64el (3.14.0-4) ... 119s Selecting previously unselected package pybuild-plugin-autopkgtest. 119s Preparing to unpack .../075-pybuild-plugin-autopkgtest_6.20251029_all.deb ... 119s Unpacking pybuild-plugin-autopkgtest (6.20251029) ... 119s Selecting previously unselected package python3-pyproject-hooks. 119s Preparing to unpack .../076-python3-pyproject-hooks_1.2.0-1_all.deb ... 119s Unpacking python3-pyproject-hooks (1.2.0-1) ... 119s Selecting previously unselected package python3-wheel. 119s Preparing to unpack .../077-python3-wheel_0.46.1-2_all.deb ... 119s Unpacking python3-wheel (0.46.1-2) ... 119s Selecting previously unselected package python3-build. 119s Preparing to unpack .../078-python3-build_1.2.2-4_all.deb ... 119s Unpacking python3-build (1.2.2-4) ... 119s Selecting previously unselected package python3-installer. 119s Preparing to unpack .../079-python3-installer_0.7.0+dfsg1-3_all.deb ... 119s Unpacking python3-installer (0.7.0+dfsg1-3) ... 119s Selecting previously unselected package pybuild-plugin-pyproject. 119s Preparing to unpack .../080-pybuild-plugin-pyproject_6.20251029_all.deb ... 119s Unpacking pybuild-plugin-pyproject (6.20251029) ... 119s Selecting previously unselected package python3-aiooui. 119s Preparing to unpack .../081-python3-aiooui_0.1.9-1_all.deb ... 119s Unpacking python3-aiooui (0.1.9-1) ... 119s Selecting previously unselected package python3.14. 119s Preparing to unpack .../082-python3.14_3.14.0-4_ppc64el.deb ... 119s Unpacking python3.14 (3.14.0-4) ... 119s Selecting previously unselected package python3-all. 119s Preparing to unpack .../083-python3-all_3.13.9-2_ppc64el.deb ... 119s Unpacking python3-all (3.13.9-2) ... 119s Selecting previously unselected package python3-async-generator. 119s Preparing to unpack .../084-python3-async-generator_1.10-7_all.deb ... 119s Unpacking python3-async-generator (1.10-7) ... 119s Selecting previously unselected package python3-async-interrupt. 119s Preparing to unpack .../085-python3-async-interrupt_1.2.2-1_all.deb ... 119s Unpacking python3-async-interrupt (1.2.2-1) ... 119s Selecting previously unselected package python3-dbus-fast. 119s Preparing to unpack .../086-python3-dbus-fast_3.1.2-1_ppc64el.deb ... 119s Unpacking python3-dbus-fast (3.1.2-1) ... 119s Selecting previously unselected package python3-bleak. 119s Preparing to unpack .../087-python3-bleak_1.1.1-1_all.deb ... 119s Unpacking python3-bleak (1.1.1-1) ... 119s Selecting previously unselected package python3-uart-devices. 119s Preparing to unpack .../088-python3-uart-devices_0.1.1-1_all.deb ... 119s Unpacking python3-uart-devices (0.1.1-1) ... 119s Selecting previously unselected package python3-usb-devices. 119s Preparing to unpack .../089-python3-usb-devices_0.4.5-2_all.deb ... 119s Unpacking python3-usb-devices (0.4.5-2) ... 119s Selecting previously unselected package python3-bluetooth-adapters. 119s Preparing to unpack .../090-python3-bluetooth-adapters_2.1.1-1_all.deb ... 119s Unpacking python3-bluetooth-adapters (2.1.1-1) ... 119s Selecting previously unselected package python3-bleak-retry-connector. 119s Preparing to unpack .../091-python3-bleak-retry-connector_4.4.4-1_all.deb ... 119s Unpacking python3-bleak-retry-connector (4.4.4-1) ... 119s Selecting previously unselected package python3-btsocket. 119s Preparing to unpack .../092-python3-btsocket_0.3.0-1_all.deb ... 119s Unpacking python3-btsocket (0.3.0-1) ... 119s Selecting previously unselected package python3-pyric. 119s Preparing to unpack .../093-python3-pyric_0.1.6.4+git20170421.0562b17-1_all.deb ... 119s Unpacking python3-pyric (0.1.6.4+git20170421.0562b17-1) ... 119s Selecting previously unselected package sphinx-rtd-theme-common. 119s Preparing to unpack .../094-sphinx-rtd-theme-common_3.0.2+dfsg-3_all.deb ... 119s Unpacking sphinx-rtd-theme-common (3.0.2+dfsg-3) ... 119s Selecting previously unselected package python3-bluetooth-auto-recovery. 119s Preparing to unpack .../095-python3-bluetooth-auto-recovery_1.5.3-1_all.deb ... 119s Unpacking python3-bluetooth-auto-recovery (1.5.3-1) ... 119s Selecting previously unselected package python3-bluetooth-data-tools. 119s Preparing to unpack .../096-python3-bluetooth-data-tools_1.28.4-1_ppc64el.deb ... 119s Unpacking python3-bluetooth-data-tools (1.28.4-1) ... 119s Selecting previously unselected package python3-coverage. 119s Preparing to unpack .../097-python3-coverage_7.8.2+dfsg1-1_ppc64el.deb ... 119s Unpacking python3-coverage (7.8.2+dfsg1-1) ... 119s Selecting previously unselected package python3-freezegun. 119s Preparing to unpack .../098-python3-freezegun_1.5.1-1.2_all.deb ... 119s Unpacking python3-freezegun (1.5.1-1.2) ... 119s Selecting previously unselected package python3-habluetooth. 119s Preparing to unpack .../099-python3-habluetooth_4.0.1-1_ppc64el.deb ... 119s Unpacking python3-habluetooth (4.0.1-1) ... 119s Selecting previously unselected package python3-iniconfig. 119s Preparing to unpack .../100-python3-iniconfig_2.1.0-1_all.deb ... 119s Unpacking python3-iniconfig (2.1.0-1) ... 119s Selecting previously unselected package python3-mdit-py-plugins. 119s Preparing to unpack .../101-python3-mdit-py-plugins_0.5.0-1_all.deb ... 119s Unpacking python3-mdit-py-plugins (0.5.0-1) ... 119s Selecting previously unselected package python3-myst-parser. 119s Preparing to unpack .../102-python3-myst-parser_4.0.1-1_all.deb ... 119s Unpacking python3-myst-parser (4.0.1-1) ... 119s Selecting previously unselected package python3-pluggy. 119s Preparing to unpack .../103-python3-pluggy_1.6.0-1_all.deb ... 119s Unpacking python3-pluggy (1.6.0-1) ... 119s Selecting previously unselected package python3-poetry-core. 119s Preparing to unpack .../104-python3-poetry-core_2.2.1-2_all.deb ... 119s Unpacking python3-poetry-core (2.2.1-2) ... 119s Selecting previously unselected package python3-pytest. 119s Preparing to unpack .../105-python3-pytest_8.3.5-2_all.deb ... 119s Unpacking python3-pytest (8.3.5-2) ... 119s Selecting previously unselected package python3-pytest-asyncio. 119s Preparing to unpack .../106-python3-pytest-asyncio_0.25.1-1_all.deb ... 119s Unpacking python3-pytest-asyncio (0.25.1-1) ... 119s Selecting previously unselected package libjs-jquery-hotkeys. 119s Preparing to unpack .../107-libjs-jquery-hotkeys_0.2.0-1_all.deb ... 119s Unpacking libjs-jquery-hotkeys (0.2.0-1) ... 119s Selecting previously unselected package libjs-jquery-isonscreen. 119s Preparing to unpack .../108-libjs-jquery-isonscreen_1.2.0-2_all.deb ... 119s Unpacking libjs-jquery-isonscreen (1.2.0-2) ... 119s Selecting previously unselected package python3-pytest-cov. 119s Preparing to unpack .../109-python3-pytest-cov_5.0.0-1_all.deb ... 119s Unpacking python3-pytest-cov (5.0.0-1) ... 119s Setting up dh-python (6.20251029) ... 120s Setting up python3-pyric (0.1.6.4+git20170421.0562b17-1) ... 120s Setting up python3-iniconfig (2.1.0-1) ... 120s Setting up python3-aiooui (0.1.9-1) ... 120s Setting up python3-uart-devices (0.1.1-1) ... 120s Setting up fonts-lato (2.015-1build1) ... 120s Setting up python3-usb-devices (0.4.5-2) ... 121s Setting up python3-async-generator (1.10-7) ... 121s Setting up python3-bluetooth-data-tools (1.28.4-1) ... 121s Setting up python3-defusedxml (0.7.1-3) ... 121s Setting up libarchive-zip-perl (1.68-1) ... 121s Setting up python3-alabaster (0.7.16-0.1) ... 121s Setting up libdebhelper-perl (13.24.2ubuntu1) ... 121s Setting up libpython3.14-minimal:ppc64el (3.14.0-4) ... 121s Setting up python3-mdit-py-plugins (0.5.0-1) ... 121s Setting up m4 (1.4.20-2) ... 121s Setting up python3-coverage (7.8.2+dfsg1-1) ... 122s Setting up libjs-jquery-throttle-debounce (1.1+dfsg.1-2) ... 122s Setting up libgomp1:ppc64el (15.2.0-9ubuntu1) ... 122s Setting up python3-wheel (0.46.1-2) ... 122s Setting up python3-btsocket (0.3.0-1) ... 122s Setting up libasound2-data (1.2.14-2ubuntu1) ... 122s Setting up python3-roman (5.2-1) ... 122s Setting up autotools-dev (20240727.1) ... 122s Setting up libasound2t64:ppc64el (1.2.14-2ubuntu1) ... 122s Setting up python3-pyproject-hooks (1.2.0-1) ... 122s Setting up python3-accessible-pygments (0.0.5-2) ... 123s Setting up python3-snowballstemmer (3.0.1-1) ... 123s Setting up python3-poetry-core (2.2.1-2) ... 124s Setting up libquadmath0:ppc64el (15.2.0-9ubuntu1) ... 124s Setting up libmpc3:ppc64el (1.3.1-2) ... 124s Setting up autopoint (0.23.2-1) ... 124s Setting up python3-installer (0.7.0+dfsg1-3) ... 124s Setting up autoconf (2.72-3.1ubuntu1) ... 124s Setting up python3-pluggy (1.6.0-1) ... 124s Setting up python3-async-interrupt (1.2.2-1) ... 124s Setting up libubsan1:ppc64el (15.2.0-9ubuntu1) ... 124s Setting up dwz (0.16-2) ... 124s Setting up libasan8:ppc64el (15.2.0-9ubuntu1) ... 124s Setting up libjson-perl (4.10000-1) ... 124s Setting up debugedit (1:5.2-3) ... 124s Setting up python3-roman-numerals (3.1.0-2) ... 124s Setting up sgml-base (1.31+nmu1) ... 124s Setting up libtsan2:ppc64el (15.2.0-9ubuntu1) ... 124s Setting up libjs-jquery (3.7.1+dfsg+~3.5.33-1build1) ... 125s Setting up libjs-jquery-hotkeys (0.2.0-1) ... 125s Setting up libisl23:ppc64el (0.27-1) ... 125s Setting up python3-build (1.2.2-4) ... 125s Setting up python3-soupsieve (2.7-2) ... 125s Setting up fonts-font-awesome (5.0.10+really4.7.0~dfsg-4.1build1) ... 125s Setting up sphinx-rtd-theme-common (3.0.2+dfsg-3) ... 125s Setting up python3.14-minimal (3.14.0-4) ... 126s Setting up libcc1-0:ppc64el (15.2.0-9ubuntu1) ... 126s Setting up python3-freezegun (1.5.1-1.2) ... 126s Setting up liblsan0:ppc64el (15.2.0-9ubuntu1) ... 126s Setting up libitm1:ppc64el (15.2.0-9ubuntu1) ... 126s Setting up libjs-underscore (1.13.4~dfsg+~1.11.4-3) ... 126s Setting up python3-imagesize (1.4.1-1build1) ... 126s Setting up automake (1:1.18.1-3) ... 126s update-alternatives: using /usr/bin/automake-1.18 to provide /usr/bin/automake (automake) in auto mode 126s Setting up libfile-stripnondeterminism-perl (1.15.0-1) ... 126s Setting up gettext (0.23.2-1) ... 126s Setting up libgcc-15-dev:ppc64el (15.2.0-9ubuntu1) ... 126s Setting up libpython3.14-stdlib:ppc64el (3.14.0-4) ... 126s Setting up pybuild-plugin-pyproject (6.20251029) ... 126s Setting up python3-pytest (8.3.5-2) ... 127s Setting up python3-bs4 (4.14.2-1) ... 127s Setting up intltool-debian (0.35.0+20060710.6build1) ... 127s Setting up bluez (5.84-1) ... 127s Created symlink '/etc/systemd/user/default.target.wants/mpris-proxy.service' → '/usr/lib/systemd/user/mpris-proxy.service'. 128s Created symlink '/etc/systemd/system/dbus-org.bluez.service' → '/usr/lib/systemd/system/bluetooth.service'. 128s Created symlink '/etc/systemd/system/bluetooth.target.wants/bluetooth.service' → '/usr/lib/systemd/system/bluetooth.service'. 128s Setting up cpp-15-powerpc64le-linux-gnu (15.2.0-9ubuntu1) ... 128s Setting up libstdc++-15-dev:ppc64el (15.2.0-9ubuntu1) ... 128s Setting up libjs-jquery-metadata (12-4) ... 128s Setting up libjs-jquery-isonscreen (1.2.0-2) ... 128s Setting up libjs-sphinxdoc (8.2.3-1ubuntu2) ... 128s Setting up python3-pytest-asyncio (0.25.1-1) ... 128s Setting up dh-strip-nondeterminism (1.15.0-1) ... 128s Setting up libjs-jquery-tablesorter (1:2.31.3+dfsg1-4) ... 128s Setting up cpp-15 (15.2.0-9ubuntu1) ... 128s Setting up xml-core (0.19) ... 129s Setting up python3.14 (3.14.0-4) ... 130s Setting up cpp-powerpc64le-linux-gnu (4:15.2.0-4ubuntu1) ... 130s Setting up python3-dbus-fast (3.1.2-1) ... 130s Setting up gcc-15-powerpc64le-linux-gnu (15.2.0-9ubuntu1) ... 130s Setting up po-debconf (1.0.21+nmu1) ... 130s Setting up python3-all (3.13.9-2) ... 130s Setting up python3-pytest-cov (5.0.0-1) ... 130s Setting up gcc-15 (15.2.0-9ubuntu1) ... 130s Setting up gcc-powerpc64le-linux-gnu (4:15.2.0-4ubuntu1) ... 130s Setting up sphinx-common (8.2.3-1ubuntu2) ... 130s Setting up cpp (4:15.2.0-4ubuntu1) ... 130s Setting up g++-15-powerpc64le-linux-gnu (15.2.0-9ubuntu1) ... 130s Setting up python3-bleak (1.1.1-1) ... 130s Setting up python3-bluetooth-adapters (2.1.1-1) ... 130s Setting up libtool (2.5.4-7) ... 130s Setting up python3-bleak-retry-connector (4.4.4-1) ... 131s Setting up gcc (4:15.2.0-4ubuntu1) ... 131s Setting up dh-autoreconf (21) ... 131s Setting up python3-bluetooth-auto-recovery (1.5.3-1) ... 131s Setting up python3-habluetooth (4.0.1-1) ... 131s Setting up g++-15 (15.2.0-9ubuntu1) ... 131s Setting up g++-powerpc64le-linux-gnu (4:15.2.0-4ubuntu1) ... 131s Setting up debhelper (13.24.2ubuntu1) ... 131s Setting up g++ (4:15.2.0-4ubuntu1) ... 131s update-alternatives: using /usr/bin/g++ to provide /usr/bin/c++ (c++) in auto mode 131s Setting up build-essential (12.12ubuntu2) ... 131s Setting up pybuild-plugin-autopkgtest (6.20251029) ... 131s Processing triggers for install-info (7.2-5) ... 131s Processing triggers for libc-bin (2.42-2ubuntu2) ... 131s Processing triggers for systemd (257.9-0ubuntu2) ... 131s Processing triggers for man-db (2.13.1-1) ... 134s Processing triggers for dbus (1.16.2-2ubuntu2) ... 134s Processing triggers for sgml-base (1.31+nmu1) ... 134s Setting up docutils-common (0.22.3+dfsg-1) ... 134s Processing triggers for sgml-base (1.31+nmu1) ... 134s Setting up python3-docutils (0.22.3+dfsg-1) ... 134s Setting up python3-sphinx (8.2.3-1ubuntu2) ... 136s Setting up python3-myst-parser (4.0.1-1) ... 136s Setting up sphinx-basic-ng (1.0.0~beta2-1) ... 136s Setting up furo (2025.09.25+dfsg-2) ... 137s autopkgtest [03:08:57]: test pybuild-autopkgtest: pybuild-autopkgtest 137s autopkgtest [03:08:57]: test pybuild-autopkgtest: [----------------------- 137s pybuild-autopkgtest 138s I: pybuild base:317: cd /tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build; python3.14 -m pytest --no-cov --ignore=tests/test_benchmark_base_scanner.py 138s /usr/lib/python3/dist-packages/pytest_asyncio/plugin.py:207: PytestDeprecationWarning: The configuration option "asyncio_default_fixture_loop_scope" is unset. 138s The event loop scope for asynchronous fixtures will default to the fixture caching scope. Future versions of pytest-asyncio will default the loop scope for asynchronous fixtures to function scope. Set the default fixture loop scope explicitly in order to avoid unexpected behavior in the future. Valid fixture loop scopes are: "function", "class", "module", "package", "session" 138s 138s warnings.warn(PytestDeprecationWarning(_DEFAULT_FIXTURE_LOOP_SCOPE_UNSET)) 138s ============================= test session starts ============================== 138s platform linux -- Python 3.14.0, pytest-8.3.5, pluggy-1.6.0 -- /usr/bin/python3.14 138s cachedir: .pytest_cache 138s rootdir: /tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build 138s configfile: pyproject.toml 138s plugins: typeguard-4.4.2, asyncio-0.25.1, cov-5.0.0 138s asyncio: mode=Mode.STRICT, asyncio_default_fixture_loop_scope=None 139s collecting ... collected 90 items 139s 139s tests/test_base_scanner.py::test_remote_scanner[None] 139s -------------------------------- live log setup -------------------------------- 139s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 139s WARNING habluetooth.manager:manager.py:189 BluetoothManager: does not implement _discover_service_info, subclasses must implement this method to consume discovery data 139s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 139s -------------------------------- live log call --------------------------------- 139s DEBUG habluetooth.manager:manager.py:765 Registering scanner esp32 139s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner esp32 139s PASSED [ 1%] 139s tests/test_base_scanner.py::test_remote_scanner[w] 139s -------------------------------- live log setup -------------------------------- 139s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 139s -------------------------------- live log call --------------------------------- 139s DEBUG habluetooth.manager:manager.py:765 Registering scanner esp32 139s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner esp32 139s PASSED [ 2%] 139s tests/test_base_scanner.py::test_remote_scanner_expires_connectable 139s -------------------------------- live log setup -------------------------------- 139s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 139s -------------------------------- live log call --------------------------------- 139s DEBUG habluetooth.manager:manager.py:765 Registering scanner esp32 139s DEBUG habluetooth.base_scanner:base_scanner.py:210 esp32: Scanner watchdog time_since_last_detection: 196.003429175 139s DEBUG habluetooth.base_scanner:base_scanner.py:225 esp32: Bluetooth scanner has gone quiet for 196.003429175s, check logs on the scanner device for more information 139s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner esp32 139s PASSED [ 3%] 139s tests/test_base_scanner.py::test_remote_scanner_expires_non_connectable 139s -------------------------------- live log setup -------------------------------- 139s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 139s -------------------------------- live log call --------------------------------- 139s DEBUG habluetooth.manager:manager.py:765 Registering scanner esp32 139s DEBUG habluetooth.base_scanner:base_scanner.py:210 esp32: Scanner watchdog time_since_last_detection: 196.00248898799998 139s DEBUG habluetooth.base_scanner:base_scanner.py:225 esp32: Bluetooth scanner has gone quiet for 196.00248898799998s, check logs on the scanner device for more information 139s DEBUG habluetooth.base_scanner:base_scanner.py:210 esp32: Scanner watchdog time_since_last_detection: 901.0024889880001 139s DEBUG habluetooth.base_scanner:base_scanner.py:225 esp32: Bluetooth scanner has gone quiet for 901.0024889880001s, check logs on the scanner device for more information 139s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner esp32 139s PASSED [ 4%] 139s tests/test_base_scanner.py::test_base_scanner_connecting_behavior 139s -------------------------------- live log setup -------------------------------- 139s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 139s -------------------------------- live log call --------------------------------- 139s DEBUG habluetooth.manager:manager.py:765 Registering scanner esp32 139s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner esp32 139s PASSED [ 5%] 139s tests/test_base_scanner.py::test_scanner_stops_responding 139s -------------------------------- live log setup -------------------------------- 139s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 139s -------------------------------- live log call --------------------------------- 139s DEBUG habluetooth.manager:manager.py:765 Registering scanner esp32 139s DEBUG habluetooth.base_scanner:base_scanner.py:210 esp32: Scanner watchdog time_since_last_detection: 120.00501415 139s DEBUG habluetooth.base_scanner:base_scanner.py:225 esp32: Bluetooth scanner has gone quiet for 120.00501415s, check logs on the scanner device for more information 139s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner esp32 139s PASSED [ 6%] 139s tests/test_base_scanner.py::test_merge_manufacturer_data_history_existing 139s -------------------------------- live log setup -------------------------------- 139s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 139s -------------------------------- live log call --------------------------------- 139s DEBUG habluetooth.manager:manager.py:765 Registering scanner esp32 139s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner esp32 139s PASSED [ 7%] 139s tests/test_base_scanner.py::test_merge_manufacturer_data_history_new 139s -------------------------------- live log setup -------------------------------- 139s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 139s -------------------------------- live log call --------------------------------- 139s DEBUG habluetooth.manager:manager.py:765 Registering scanner esp32 139s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner esp32 139s PASSED [ 8%] 139s tests/test_base_scanner.py::test_filter_apple_data 139s -------------------------------- live log setup -------------------------------- 139s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 139s -------------------------------- live log call --------------------------------- 139s DEBUG habluetooth.manager:manager.py:765 Registering scanner esp32 139s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner esp32 139s PASSED [ 10%] 139s tests/test_base_scanner.py::test_connection_history_count_in_progress 139s -------------------------------- live log setup -------------------------------- 139s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (AA:BB:CC:DD:EE:00) 139s PASSED [ 11%] 139s ------------------------------ live log teardown ------------------------------- 139s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (AA:BB:CC:DD:EE:00) 139s 139s tests/test_base_scanner.py::test_connection_history_failure_count 139s -------------------------------- live log setup -------------------------------- 139s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (AA:BB:CC:DD:EE:00) 139s -------------------------------- live log call --------------------------------- 139s WARNING habluetooth.base_scanner:base_scanner.py:131 Removing a non-existing connecting hci0 (AA:BB:CC:DD:EE:00) 44:44:33:11:23:12 139s PASSED [ 12%] 139s ------------------------------ live log teardown ------------------------------- 139s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (AA:BB:CC:DD:EE:00) 139s 139s tests/test_init.py::test_create_scanner 139s -------------------------------- live log setup -------------------------------- 139s WARNING habluetooth.manager:manager.py:189 BluetoothManager: does not implement _discover_service_info, subclasses must implement this method to consume discovery data 139s PASSED [ 13%] 139s tests/test_init.py::test_create_remote_scanner PASSED [ 14%] 139s tests/test_init.py::test__async_on_advertisement PASSED [ 15%] 139s tests/test_init.py::test__async_on_advertisement_first PASSED [ 16%] 139s tests/test_init.py::test__async_on_advertisement_prefers_longest_local_name PASSED [ 17%] 139s tests/test_init.py::test_create_ha_scanner PASSED [ 18%] 139s tests/test_manager.py::test_async_recover_failed_adapters 139s -------------------------------- live log setup -------------------------------- 139s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 139s -------------------------------- live log call --------------------------------- 139s WARNING habluetooth.manager:manager.py:189 BluetoothManager: does not implement _discover_service_info, subclasses must implement this method to consume discovery data 139s PASSED [ 20%] 139s tests/test_manager.py::test_create_manager 139s -------------------------------- live log setup -------------------------------- 139s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 139s -------------------------------- live log call --------------------------------- 139s WARNING habluetooth.manager:manager.py:189 BluetoothManager: does not implement _discover_service_info, subclasses must implement this method to consume discovery data 139s PASSED [ 21%] 139s tests/test_manager.py::test_async_register_disappeared_callback 139s -------------------------------- live log setup -------------------------------- 139s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 139s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (AA:BB:CC:DD:EE:00) 139s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci1 (AA:BB:CC:DD:EE:11) 139s -------------------------------- live log call --------------------------------- 139s ERROR habluetooth.manager:manager.py:425 Error in disappeared callback 139s Traceback (most recent call last): 139s File "/usr/lib/python3/dist-packages/habluetooth/manager.py", line 423, in _async_check_unavailable 139s disappear_callback(address) 139s ~~~~~~~~~~~~~~~~~~^^^^^^^^^ 139s File "/tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/test_manager.py", line 188, in _failing_callback 139s raise ValueError("This is a test") 139s ValueError: This is a test 139s PASSED [ 22%] 139s ------------------------------ live log teardown ------------------------------- 139s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci1 (AA:BB:CC:DD:EE:11) 139s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (AA:BB:CC:DD:EE:00) 139s 139s tests/test_manager.py::test_async_register_allocation_callback 139s -------------------------------- live log setup -------------------------------- 139s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 139s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (AA:BB:CC:DD:EE:00) 139s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci1 (AA:BB:CC:DD:EE:11) 139s -------------------------------- live log call --------------------------------- 139s ERROR habluetooth.manager:manager.py:850 Error in allocation callback 139s Traceback (most recent call last): 139s File "/usr/lib/python3/dist-packages/habluetooth/manager.py", line 848, in async_on_allocation_changed 139s callback_(ha_slot_allocations) 139s ~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^ 139s File "/tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/test_manager.py", line 259, in _failing_callback 139s raise ValueError("This is a test") 139s ValueError: This is a test 139s ERROR habluetooth.manager:manager.py:850 Error in allocation callback 139s Traceback (most recent call last): 139s File "/usr/lib/python3/dist-packages/habluetooth/manager.py", line 848, in async_on_allocation_changed 139s callback_(ha_slot_allocations) 139s ~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^ 139s File "/tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/test_manager.py", line 259, in _failing_callback 139s raise ValueError("This is a test") 139s ValueError: This is a test 139s PASSED [ 23%] 139s ------------------------------ live log teardown ------------------------------- 139s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci1 (AA:BB:CC:DD:EE:11) 139s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (AA:BB:CC:DD:EE:00) 139s 139s tests/test_manager.py::test_async_register_allocation_callback_non_connectable 139s -------------------------------- live log setup -------------------------------- 139s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 139s DEBUG habluetooth.manager:manager.py:765 Registering scanner non connectable (AA:BB:CC:DD:EE:FF) 139s PASSED [ 24%] 139s ------------------------------ live log teardown ------------------------------- 139s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner non connectable (AA:BB:CC:DD:EE:FF) 139s 139s tests/test_manager.py::test_async_register_scanner_registration_callback 139s -------------------------------- live log setup -------------------------------- 139s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 139s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (AA:BB:CC:DD:EE:00) 139s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci1 (AA:BB:CC:DD:EE:11) 139s -------------------------------- live log call --------------------------------- 139s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci3 (AA:BB:CC:DD:EE:33) 139s ERROR habluetooth.manager:manager.py:867 Error in scanner callback 139s Traceback (most recent call last): 139s File "/usr/lib/python3/dist-packages/habluetooth/manager.py", line 865, in _async_on_scanner_registration 139s callback_(HaScannerRegistration(event, scanner)) 139s ~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ 139s File "/tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/test_manager.py", line 381, in _failing_callback 139s raise ValueError("This is a test") 139s ValueError: This is a test 139s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci3 (AA:BB:CC:DD:EE:33) 139s ERROR habluetooth.manager:manager.py:867 Error in scanner callback 139s Traceback (most recent call last): 139s File "/usr/lib/python3/dist-packages/habluetooth/manager.py", line 865, in _async_on_scanner_registration 139s callback_(HaScannerRegistration(event, scanner)) 139s ~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ 139s File "/tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/test_manager.py", line 381, in _failing_callback 139s raise ValueError("This is a test") 139s ValueError: This is a test 139s PASSED [ 25%] 139s ------------------------------ live log teardown ------------------------------- 139s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci1 (AA:BB:CC:DD:EE:11) 139s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (AA:BB:CC:DD:EE:00) 139s 139s tests/test_manager.py::test_async_register_scanner_with_connection_slots 139s -------------------------------- live log setup -------------------------------- 139s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 139s -------------------------------- live log call --------------------------------- 139s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci3 (AA:BB:CC:DD:EE:33) 139s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci3 (AA:BB:CC:DD:EE:33) 139s PASSED [ 26%] 139s tests/test_manager.py::test_diagnostics 139s -------------------------------- live log setup -------------------------------- 139s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 139s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (AA:BB:CC:DD:EE:00) 139s PASSED [ 27%] 139s ------------------------------ live log teardown ------------------------------- 139s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (AA:BB:CC:DD:EE:00) 139s 139s tests/test_manager.py::test_advertisements_do_not_switch_adapters_for_no_reason 139s -------------------------------- live log setup -------------------------------- 139s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 139s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (AA:BB:CC:DD:EE:00) 139s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci1 (AA:BB:CC:DD:EE:11) 139s PASSED [ 28%] 139s ------------------------------ live log teardown ------------------------------- 139s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci1 (AA:BB:CC:DD:EE:11) 139s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (AA:BB:CC:DD:EE:00) 139s 139s tests/test_manager.py::test_switching_adapters_based_on_rssi 139s -------------------------------- live log setup -------------------------------- 139s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 139s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (AA:BB:CC:DD:EE:00) 139s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci1 (AA:BB:CC:DD:EE:11) 139s -------------------------------- live log call --------------------------------- 139s DEBUG habluetooth.manager:manager.py:480 wohand_good_signal (44:44:33:11:23:45): Switching from hci0 (AA:BB:CC:DD:EE:00) [connectable] to hci1 (AA:BB:CC:DD:EE:11) [connectable] (new rssi:-60 - threshold:16 > old rssi:-100) 139s PASSED [ 30%] 139s ------------------------------ live log teardown ------------------------------- 139s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci1 (AA:BB:CC:DD:EE:11) 139s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (AA:BB:CC:DD:EE:00) 139s 139s tests/test_manager.py::test_switching_adapters_based_on_zero_rssi 139s -------------------------------- live log setup -------------------------------- 139s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 139s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (AA:BB:CC:DD:EE:00) 139s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci1 (AA:BB:CC:DD:EE:11) 139s -------------------------------- live log call --------------------------------- 139s DEBUG habluetooth.manager:manager.py:480 wohand_good_signal (44:44:33:11:23:45): Switching from hci0 (AA:BB:CC:DD:EE:00) [connectable] to hci1 (AA:BB:CC:DD:EE:11) [connectable] (new rssi:-60 - threshold:16 > old rssi:0) 139s PASSED [ 31%] 139s ------------------------------ live log teardown ------------------------------- 139s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci1 (AA:BB:CC:DD:EE:11) 139s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (AA:BB:CC:DD:EE:00) 139s 139s tests/test_manager.py::test_switching_adapters_based_on_stale 139s -------------------------------- live log setup -------------------------------- 139s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 139s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (AA:BB:CC:DD:EE:00) 139s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci1 (AA:BB:CC:DD:EE:11) 139s -------------------------------- live log call --------------------------------- 139s DEBUG habluetooth.manager:manager.py:463 wohand_poor_signal_hci1 (44:44:33:11:23:41): Switching from hci0 (AA:BB:CC:DD:EE:00) [connectable] to hci1 [connectable] (time elapsed:901.0 > stale seconds:900) 139s PASSED [ 32%] 139s ------------------------------ live log teardown ------------------------------- 139s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci1 (AA:BB:CC:DD:EE:11) 139s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (AA:BB:CC:DD:EE:00) 139s 139s tests/test_manager.py::test_switching_adapters_based_on_stale_with_discovered_interval 139s -------------------------------- live log setup -------------------------------- 139s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 139s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (AA:BB:CC:DD:EE:00) 139s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci1 (AA:BB:CC:DD:EE:11) 139s -------------------------------- live log call --------------------------------- 139s DEBUG habluetooth.manager:manager.py:463 wohand_poor_signal_hci1 (44:44:33:11:23:41): Switching from hci0 (AA:BB:CC:DD:EE:00) [connectable] to hci1 (AA:BB:CC:DD:EE:11) [connectable] (time elapsed:16.0 > stale seconds:15) 139s PASSED [ 33%] 139s ------------------------------ live log teardown ------------------------------- 139s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci1 (AA:BB:CC:DD:EE:11) 139s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (AA:BB:CC:DD:EE:00) 139s 139s tests/test_manager.py::test_switching_adapters_based_on_rssi_connectable_to_non_connectable 139s -------------------------------- live log setup -------------------------------- 139s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 139s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (AA:BB:CC:DD:EE:00) 139s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci1 (AA:BB:CC:DD:EE:11) 139s -------------------------------- live log call --------------------------------- 139s DEBUG habluetooth.manager:manager.py:480 wohand_good_signal (44:44:33:11:23:45): Switching from hci0 (AA:BB:CC:DD:EE:00) [connectable] to hci1 (new rssi:-60 - threshold:16 > old rssi:-100) 139s PASSED [ 34%] 139s ------------------------------ live log teardown ------------------------------- 139s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci1 (AA:BB:CC:DD:EE:11) 139s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (AA:BB:CC:DD:EE:00) 139s 139s tests/test_manager.py::test_connectable_advertisement_can_be_retrieved_best_path_is_non_connectable 139s -------------------------------- live log setup -------------------------------- 139s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 139s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (AA:BB:CC:DD:EE:00) 139s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci1 (AA:BB:CC:DD:EE:11) 139s PASSED [ 35%] 139s ------------------------------ live log teardown ------------------------------- 139s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci1 (AA:BB:CC:DD:EE:11) 139s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (AA:BB:CC:DD:EE:00) 139s 139s tests/test_manager.py::test_switching_adapters_when_one_goes_away 139s -------------------------------- live log setup -------------------------------- 139s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 139s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (AA:BB:CC:DD:EE:00) 139s -------------------------------- live log call --------------------------------- 139s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci2 139s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci2 139s PASSED [ 36%] 139s ------------------------------ live log teardown ------------------------------- 139s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (AA:BB:CC:DD:EE:00) 139s 139s tests/test_manager.py::test_switching_adapters_when_one_stop_scanning 139s -------------------------------- live log setup -------------------------------- 139s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 139s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (AA:BB:CC:DD:EE:00) 139s -------------------------------- live log call --------------------------------- 139s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci2 139s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci2 139s PASSED [ 37%] 139s ------------------------------ live log teardown ------------------------------- 139s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (AA:BB:CC:DD:EE:00) 139s 139s tests/test_manager.py::test_set_fallback_interval_small 139s -------------------------------- live log setup -------------------------------- 139s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 139s PASSED [ 38%] 139s tests/test_manager.py::test_set_fallback_interval_big 139s -------------------------------- live log setup -------------------------------- 139s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 139s PASSED [ 40%] 139s tests/test_manager.py::test_subclassing_bluetooth_manager 139s -------------------------------- live log setup -------------------------------- 139s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 139s -------------------------------- live log call --------------------------------- 139s WARNING habluetooth.manager:manager.py:189 TestBluetoothManager2: does not implement _discover_service_info, subclasses must implement this method to consume discovery data 139s PASSED [ 41%] 139s tests/test_models.py::test_model PASSED [ 42%] 139s tests/test_models.py::test_model_from_bleak PASSED [ 43%] 139s tests/test_models.py::test_model_from_scanner PASSED [ 44%] 139s tests/test_models.py::test_construct_service_info_bleak PASSED [ 45%] 139s tests/test_models.py::test_from_device_and_advertisement_data PASSED [ 46%] 139s tests/test_models.py::test_pyobjc_compat PASSED [ 47%] 139s tests/test_models.py::test_as_connectable PASSED [ 48%] 139s tests/test_scanner.py::test_empty_data_no_scanner 139s -------------------------------- live log setup -------------------------------- 139s WARNING habluetooth.manager:manager.py:189 BluetoothManager: does not implement _discover_service_info, subclasses must implement this method to consume discovery data 139s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 139s PASSED [ 50%] 139s tests/test_scanner.py::test_dbus_socket_missing_in_container 139s -------------------------------- live log setup -------------------------------- 139s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 139s -------------------------------- live log call --------------------------------- 139s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 139s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (1/4) 139s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 139s DEBUG habluetooth.scanner:scanner.py:462 hci0 (AA:BB:CC:DD:EE:FF): FileNotFoundError while starting bluetooth: 139s Traceback (most recent call last): 139s File "/usr/lib/python3/dist-packages/habluetooth/scanner.py", line 344, in _async_start_attempt 139s await self.scanner.start() 139s File "/usr/lib/python3.14/unittest/mock.py", line 2326, in _execute_mock_call 139s raise effect 139s FileNotFoundError 139s PASSED [ 51%] 139s tests/test_scanner.py::test_dbus_socket_missing 139s -------------------------------- live log setup -------------------------------- 139s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 139s -------------------------------- live log call --------------------------------- 139s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 139s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (1/4) 139s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 139s DEBUG habluetooth.scanner:scanner.py:462 hci0 (AA:BB:CC:DD:EE:FF): FileNotFoundError while starting bluetooth: 139s Traceback (most recent call last): 139s File "/usr/lib/python3/dist-packages/habluetooth/scanner.py", line 344, in _async_start_attempt 139s await self.scanner.start() 139s File "/usr/lib/python3.14/unittest/mock.py", line 2326, in _execute_mock_call 139s raise effect 139s FileNotFoundError 139s PASSED [ 52%] 139s tests/test_scanner.py::test_handle_cancellation 139s -------------------------------- live log setup -------------------------------- 139s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 139s -------------------------------- live log call --------------------------------- 139s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 139s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (1/4) 139s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 139s PASSED [ 53%] 139s tests/test_scanner.py::test_handle_stop_while_starting 139s -------------------------------- live log setup -------------------------------- 139s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 139s -------------------------------- live log call --------------------------------- 139s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 139s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (1/4) 139s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 139s DEBUG habluetooth.scanner:scanner.py:452 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth scanner aborted: 139s Traceback (most recent call last): 139s File "/usr/lib/python3/dist-packages/habluetooth/scanner.py", line 344, in _async_start_attempt 139s await self.scanner.start() 139s File "/tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/test_scanner.py", line 149, in _start 139s await asyncio.sleep(1000) 139s File "/usr/lib/python3.14/asyncio/tasks.py", line 702, in sleep 139s return await future 139s ^^^^^^^^^^^^ 139s asyncio.exceptions.CancelledError: Interrupted by interrupt context manager 139s 139s The above exception was the direct cause of the following exception: 139s 139s Traceback (most recent call last): 139s File "/usr/lib/python3/dist-packages/habluetooth/scanner.py", line 342, in _async_start_attempt 139s async_interrupt.interrupt(self._start_future, _AbortStartError, None), 139s ~~~~~~~~~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ 139s File "/usr/lib/python3/dist-packages/async_interrupt/__init__.py", line 90, in __aexit__ 139s raise self._exception from exc_val 139s habluetooth.scanner._AbortStartError 139s DEBUG habluetooth.scanner:scanner.py:571 hci0 (AA:BB:CC:DD:EE:FF): Scanner is already stopped 139s PASSED [ 54%] 139s tests/test_scanner.py::test_dbus_broken_pipe_in_container 139s -------------------------------- live log setup -------------------------------- 139s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 139s -------------------------------- live log call --------------------------------- 139s ERROR asyncio:base_events.py:1875 Future exception was never retrieved 139s future: 139s habluetooth.scanner._AbortStartError 139s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 139s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (1/4) 139s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 139s DEBUG habluetooth.scanner:scanner.py:480 hci0 (AA:BB:CC:DD:EE:FF): DBus connection broken: 139s Traceback (most recent call last): 139s File "/usr/lib/python3/dist-packages/habluetooth/scanner.py", line 344, in _async_start_attempt 139s await self.scanner.start() 139s File "/usr/lib/python3.14/unittest/mock.py", line 2326, in _execute_mock_call 139s raise effect 139s BrokenPipeError 139s PASSED [ 55%] 139s tests/test_scanner.py::test_dbus_broken_pipe 139s -------------------------------- live log setup -------------------------------- 139s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 139s -------------------------------- live log call --------------------------------- 139s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 139s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (1/4) 139s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 139s DEBUG habluetooth.scanner:scanner.py:480 hci0 (AA:BB:CC:DD:EE:FF): DBus connection broken: 139s Traceback (most recent call last): 139s File "/usr/lib/python3/dist-packages/habluetooth/scanner.py", line 344, in _async_start_attempt 139s await self.scanner.start() 139s File "/usr/lib/python3.14/unittest/mock.py", line 2326, in _execute_mock_call 139s raise effect 139s BrokenPipeError 139s PASSED [ 56%] 139s tests/test_scanner.py::test_invalid_dbus_message 139s -------------------------------- live log setup -------------------------------- 139s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 139s -------------------------------- live log call --------------------------------- 139s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 139s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (1/4) 139s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 139s DEBUG habluetooth.scanner:scanner.py:495 hci0 (AA:BB:CC:DD:EE:FF): Invalid DBus message received: 139s Traceback (most recent call last): 139s File "/usr/lib/python3/dist-packages/habluetooth/scanner.py", line 344, in _async_start_attempt 139s await self.scanner.start() 139s File "/usr/lib/python3.14/unittest/mock.py", line 2326, in _execute_mock_call 139s raise effect 139s dbus_fast.errors.InvalidMessageError 139s PASSED [ 57%] 139s tests/test_scanner.py::test_adapter_needs_reset_at_start[org.bluez.Error.Failed] 139s -------------------------------- live log setup -------------------------------- 139s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 139s -------------------------------- live log call --------------------------------- 139s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 139s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (1/4) 139s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 139s DEBUG habluetooth.scanner:scanner.py:434 hci0 (AA:BB:CC:DD:EE:FF): BleakError while starting bluetooth; attempt: (1/4): org.bluez.Error.Failed 139s Traceback (most recent call last): 139s File "/usr/lib/python3/dist-packages/habluetooth/scanner.py", line 344, in _async_start_attempt 139s await self.scanner.start() 139s File "/tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/test_scanner.py", line 249, in start 139s raise BleakError(error) 139s bleak.exc.BleakError: org.bluez.Error.Failed 139s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 139s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (2/4) 139s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 139s DEBUG habluetooth.scanner:scanner.py:555 hci0 (AA:BB:CC:DD:EE:FF): adapter stopped responding; executing reset 139s DEBUG habluetooth.scanner:scanner.py:557 hci0 (AA:BB:CC:DD:EE:FF): adapter reset result: True 139s DEBUG habluetooth.scanner:scanner.py:434 hci0 (AA:BB:CC:DD:EE:FF): BleakError while starting bluetooth; attempt: (2/4): org.bluez.Error.Failed 139s Traceback (most recent call last): 139s File "/usr/lib/python3/dist-packages/habluetooth/scanner.py", line 344, in _async_start_attempt 139s await self.scanner.start() 139s File "/tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/test_scanner.py", line 249, in start 139s raise BleakError(error) 139s bleak.exc.BleakError: org.bluez.Error.Failed 139s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 139s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (3/4) 139s DEBUG habluetooth.scanner:scanner.py:418 hci0 (AA:BB:CC:DD:EE:FF): Success while starting bluetooth; attempt: (3/4) 147s DEBUG bleak_retry_connector.bleak_manager:bleak_manager.py:56 Timed out trying to connect to DBus; will not try again until next restart 147s DEBUG bleak_retry_connector:__init__.py:639 Failed to restore discoveries for hci0 147s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 147s PASSED [ 58%] 147s tests/test_scanner.py::test_adapter_needs_reset_at_start[org.bluez.Error.InProgress] 147s -------------------------------- live log setup -------------------------------- 147s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 147s -------------------------------- live log call --------------------------------- 147s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 147s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (1/4) 147s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 147s DEBUG habluetooth.scanner:scanner.py:586 hci0 (AA:BB:CC:DD:EE:FF): Force stopping bluetooth discovery 147s ERROR bleak_retry_connector.bluez:bluez.py:324 Failed to stop discovery for hci0 because no manager 148s DEBUG habluetooth.scanner:scanner.py:434 hci0 (AA:BB:CC:DD:EE:FF): BleakError while starting bluetooth; attempt: (1/4): org.bluez.Error.InProgress 148s Traceback (most recent call last): 148s File "/usr/lib/python3/dist-packages/habluetooth/scanner.py", line 344, in _async_start_attempt 148s await self.scanner.start() 148s File "/tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/test_scanner.py", line 249, in start 148s raise BleakError(error) 148s bleak.exc.BleakError: org.bluez.Error.InProgress 148s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 148s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (2/4) 148s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 148s DEBUG habluetooth.scanner:scanner.py:586 hci0 (AA:BB:CC:DD:EE:FF): Force stopping bluetooth discovery 148s ERROR bleak_retry_connector.bluez:bluez.py:324 Failed to stop discovery for hci0 because no manager 148s DEBUG habluetooth.scanner:scanner.py:555 hci0 (AA:BB:CC:DD:EE:FF): adapter stopped responding; executing reset 148s DEBUG habluetooth.scanner:scanner.py:557 hci0 (AA:BB:CC:DD:EE:FF): adapter reset result: True 148s DEBUG habluetooth.scanner:scanner.py:434 hci0 (AA:BB:CC:DD:EE:FF): BleakError while starting bluetooth; attempt: (2/4): org.bluez.Error.InProgress 148s Traceback (most recent call last): 148s File "/usr/lib/python3/dist-packages/habluetooth/scanner.py", line 344, in _async_start_attempt 148s await self.scanner.start() 148s File "/tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/test_scanner.py", line 249, in start 148s raise BleakError(error) 148s bleak.exc.BleakError: org.bluez.Error.InProgress 148s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 148s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (3/4) 148s DEBUG habluetooth.scanner:scanner.py:418 hci0 (AA:BB:CC:DD:EE:FF): Success while starting bluetooth; attempt: (3/4) 148s DEBUG bleak_retry_connector:__init__.py:639 Failed to restore discoveries for hci0 148s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 148s PASSED [ 60%] 148s tests/test_scanner.py::test_adapter_needs_reset_at_start[org.bluez.Error.NotReady] 148s -------------------------------- live log setup -------------------------------- 148s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 148s -------------------------------- live log call --------------------------------- 148s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 148s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (1/4) 148s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 148s DEBUG habluetooth.scanner:scanner.py:434 hci0 (AA:BB:CC:DD:EE:FF): BleakError while starting bluetooth; attempt: (1/4): org.bluez.Error.NotReady 148s Traceback (most recent call last): 148s File "/usr/lib/python3/dist-packages/habluetooth/scanner.py", line 344, in _async_start_attempt 148s await self.scanner.start() 148s File "/tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/test_scanner.py", line 249, in start 148s raise BleakError(error) 148s bleak.exc.BleakError: org.bluez.Error.NotReady 148s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 148s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (2/4) 148s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 148s DEBUG habluetooth.scanner:scanner.py:555 hci0 (AA:BB:CC:DD:EE:FF): adapter stopped responding; executing reset 148s DEBUG habluetooth.scanner:scanner.py:557 hci0 (AA:BB:CC:DD:EE:FF): adapter reset result: True 148s DEBUG habluetooth.scanner:scanner.py:434 hci0 (AA:BB:CC:DD:EE:FF): BleakError while starting bluetooth; attempt: (2/4): org.bluez.Error.NotReady 148s Traceback (most recent call last): 148s File "/usr/lib/python3/dist-packages/habluetooth/scanner.py", line 344, in _async_start_attempt 148s await self.scanner.start() 148s File "/tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/test_scanner.py", line 249, in start 148s raise BleakError(error) 148s bleak.exc.BleakError: org.bluez.Error.NotReady 148s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 148s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (3/4) 148s DEBUG habluetooth.scanner:scanner.py:418 hci0 (AA:BB:CC:DD:EE:FF): Success while starting bluetooth; attempt: (3/4) 148s DEBUG bleak_retry_connector:__init__.py:639 Failed to restore discoveries for hci0 148s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 148s PASSED [ 61%] 148s tests/test_scanner.py::test_adapter_needs_reset_at_start[not found] 148s -------------------------------- live log setup -------------------------------- 148s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 148s -------------------------------- live log call --------------------------------- 148s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 148s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (1/4) 148s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 148s DEBUG habluetooth.scanner:scanner.py:434 hci0 (AA:BB:CC:DD:EE:FF): BleakError while starting bluetooth; attempt: (1/4): not found 148s Traceback (most recent call last): 148s File "/usr/lib/python3/dist-packages/habluetooth/scanner.py", line 344, in _async_start_attempt 148s await self.scanner.start() 148s File "/tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/test_scanner.py", line 249, in start 148s raise BleakError(error) 148s bleak.exc.BleakError: not found 148s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 148s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (2/4) 148s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 148s DEBUG habluetooth.scanner:scanner.py:555 hci0 (AA:BB:CC:DD:EE:FF): adapter stopped responding; executing reset 148s DEBUG habluetooth.scanner:scanner.py:557 hci0 (AA:BB:CC:DD:EE:FF): adapter reset result: True 148s DEBUG habluetooth.scanner:scanner.py:434 hci0 (AA:BB:CC:DD:EE:FF): BleakError while starting bluetooth; attempt: (2/4): not found 148s Traceback (most recent call last): 148s File "/usr/lib/python3/dist-packages/habluetooth/scanner.py", line 344, in _async_start_attempt 148s await self.scanner.start() 148s File "/tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/test_scanner.py", line 249, in start 148s raise BleakError(error) 148s bleak.exc.BleakError: not found 148s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 148s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (3/4) 148s DEBUG habluetooth.scanner:scanner.py:418 hci0 (AA:BB:CC:DD:EE:FF): Success while starting bluetooth; attempt: (3/4) 148s DEBUG bleak_retry_connector:__init__.py:639 Failed to restore discoveries for hci0 148s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 148s PASSED [ 62%] 148s tests/test_scanner.py::test_recovery_from_dbus_restart 148s -------------------------------- live log setup -------------------------------- 148s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 148s -------------------------------- live log call --------------------------------- 148s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 148s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (1/4) 148s DEBUG habluetooth.scanner:scanner.py:418 hci0 (AA:BB:CC:DD:EE:FF): Success while starting bluetooth; attempt: (1/4) 148s DEBUG bleak_retry_connector:__init__.py:639 Failed to restore discoveries for hci0 148s DEBUG habluetooth.base_scanner:base_scanner.py:210 hci0 (AA:BB:CC:DD:EE:FF): Scanner watchdog time_since_last_detection: 10.004491282999993 148s DEBUG habluetooth.base_scanner:base_scanner.py:210 hci0 (AA:BB:CC:DD:EE:FF): Scanner watchdog time_since_last_detection: 19.999999999999993 148s DEBUG habluetooth.base_scanner:base_scanner.py:210 hci0 (AA:BB:CC:DD:EE:FF): Scanner watchdog time_since_last_detection: 110.0 148s DEBUG habluetooth.scanner:scanner.py:517 hci0 (AA:BB:CC:DD:EE:FF): Bluetooth scanner has gone quiet for 110.0s, restarting 148s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 148s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 148s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (1/4) 148s DEBUG habluetooth.scanner:scanner.py:418 hci0 (AA:BB:CC:DD:EE:FF): Success while starting bluetooth; attempt: (1/4) 148s DEBUG bleak_retry_connector:__init__.py:639 Failed to restore discoveries for hci0 148s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 148s PASSED [ 63%] 148s tests/test_scanner.py::test_adapter_recovery 148s -------------------------------- live log setup -------------------------------- 148s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 148s -------------------------------- live log call --------------------------------- 148s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 148s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (1/4) 148s DEBUG habluetooth.scanner:scanner.py:418 hci0 (AA:BB:CC:DD:EE:FF): Success while starting bluetooth; attempt: (1/4) 148s DEBUG bleak_retry_connector:__init__.py:639 Failed to restore discoveries for hci0 148s DEBUG habluetooth.base_scanner:base_scanner.py:210 hci0 (AA:BB:CC:DD:EE:FF): Scanner watchdog time_since_last_detection: 9.999999999999993 148s DEBUG habluetooth.base_scanner:base_scanner.py:210 hci0 (AA:BB:CC:DD:EE:FF): Scanner watchdog time_since_last_detection: 19.999999999999993 148s DEBUG habluetooth.base_scanner:base_scanner.py:210 hci0 (AA:BB:CC:DD:EE:FF): Scanner watchdog time_since_last_detection: 120.0 148s DEBUG habluetooth.scanner:scanner.py:517 hci0 (AA:BB:CC:DD:EE:FF): Bluetooth scanner has gone quiet for 120.0s, restarting 148s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 148s DEBUG habluetooth.scanner:scanner.py:555 hci0 (AA:BB:CC:DD:EE:FF): adapter stopped responding; executing reset 148s DEBUG habluetooth.scanner:scanner.py:557 hci0 (AA:BB:CC:DD:EE:FF): adapter reset result: True 148s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 148s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (1/4) 148s DEBUG habluetooth.scanner:scanner.py:418 hci0 (AA:BB:CC:DD:EE:FF): Success while starting bluetooth; attempt: (1/4) 148s DEBUG bleak_retry_connector:__init__.py:639 Failed to restore discoveries for hci0 148s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 148s PASSED [ 64%] 148s tests/test_scanner.py::test_adapter_scanner_fails_to_start_first_time 148s -------------------------------- live log setup -------------------------------- 148s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 148s -------------------------------- live log call --------------------------------- 148s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 148s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (1/4) 148s DEBUG habluetooth.scanner:scanner.py:418 hci0 (AA:BB:CC:DD:EE:FF): Success while starting bluetooth; attempt: (1/4) 148s DEBUG bleak_retry_connector:__init__.py:639 Failed to restore discoveries for hci0 148s DEBUG habluetooth.base_scanner:base_scanner.py:210 hci0 (AA:BB:CC:DD:EE:FF): Scanner watchdog time_since_last_detection: 10.0 148s DEBUG habluetooth.base_scanner:base_scanner.py:210 hci0 (AA:BB:CC:DD:EE:FF): Scanner watchdog time_since_last_detection: 20.0 148s DEBUG habluetooth.base_scanner:base_scanner.py:210 hci0 (AA:BB:CC:DD:EE:FF): Scanner watchdog time_since_last_detection: 120.0 148s DEBUG habluetooth.scanner:scanner.py:517 hci0 (AA:BB:CC:DD:EE:FF): Bluetooth scanner has gone quiet for 120.0s, restarting 148s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 148s DEBUG habluetooth.scanner:scanner.py:555 hci0 (AA:BB:CC:DD:EE:FF): adapter stopped responding; executing reset 148s DEBUG habluetooth.scanner:scanner.py:557 hci0 (AA:BB:CC:DD:EE:FF): adapter reset result: True 148s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 148s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (1/4) 148s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 148s DEBUG habluetooth.scanner:scanner.py:434 hci0 (AA:BB:CC:DD:EE:FF): BleakError while starting bluetooth; attempt: (1/4): Failed to start 148s Traceback (most recent call last): 148s File "/usr/lib/python3/dist-packages/habluetooth/scanner.py", line 344, in _async_start_attempt 148s await self.scanner.start() 148s File "/tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/test_scanner.py", line 485, in start 148s raise BleakError("Failed to start") 148s bleak.exc.BleakError: Failed to start 148s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 148s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (2/4) 148s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 148s DEBUG habluetooth.scanner:scanner.py:434 hci0 (AA:BB:CC:DD:EE:FF): BleakError while starting bluetooth; attempt: (2/4): Failed to start 148s Traceback (most recent call last): 148s File "/usr/lib/python3/dist-packages/habluetooth/scanner.py", line 344, in _async_start_attempt 148s await self.scanner.start() 148s File "/tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/test_scanner.py", line 485, in start 148s raise BleakError("Failed to start") 148s bleak.exc.BleakError: Failed to start 148s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 148s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (3/4) 148s DEBUG habluetooth.scanner:scanner.py:418 hci0 (AA:BB:CC:DD:EE:FF): Success while starting bluetooth; attempt: (3/4) 148s DEBUG bleak_retry_connector:__init__.py:639 Failed to restore discoveries for hci0 148s DEBUG habluetooth.base_scanner:base_scanner.py:210 hci0 (AA:BB:CC:DD:EE:FF): Scanner watchdog time_since_last_detection: 90.006256157 148s DEBUG habluetooth.scanner:scanner.py:517 hci0 (AA:BB:CC:DD:EE:FF): Bluetooth scanner has gone quiet for 90.006256157s, restarting 148s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 148s DEBUG habluetooth.scanner:scanner.py:555 hci0 (AA:BB:CC:DD:EE:FF): adapter stopped responding; executing reset 148s DEBUG habluetooth.scanner:scanner.py:557 hci0 (AA:BB:CC:DD:EE:FF): adapter reset result: True 148s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 148s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (1/4) 148s DEBUG habluetooth.scanner:scanner.py:418 hci0 (AA:BB:CC:DD:EE:FF): Success while starting bluetooth; attempt: (1/4) 148s DEBUG bleak_retry_connector:__init__.py:639 Failed to restore discoveries for hci0 148s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 148s PASSED [ 65%] 148s tests/test_scanner.py::test_adapter_fails_to_start_and_takes_a_bit_to_init 148s -------------------------------- live log setup -------------------------------- 148s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 148s -------------------------------- live log call --------------------------------- 148s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 148s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (1/4) 148s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 148s DEBUG habluetooth.scanner:scanner.py:402 hci0 (AA:BB:CC:DD:EE:FF): Waiting for adapter to initialize; attempt (1/4) 148s DEBUG habluetooth.scanner:scanner.py:434 hci0 (AA:BB:CC:DD:EE:FF): BleakError while starting bluetooth; attempt: (1/4): org.freedesktop.DBus.Error.UnknownObject 148s Traceback (most recent call last): 148s File "/usr/lib/python3/dist-packages/habluetooth/scanner.py", line 344, in _async_start_attempt 148s await self.scanner.start() 148s File "/tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/test_scanner.py", line 599, in start 148s raise BleakError("org.freedesktop.DBus.Error.UnknownObject") 148s bleak.exc.BleakError: org.freedesktop.DBus.Error.UnknownObject 148s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 148s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (2/4) 148s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 148s DEBUG habluetooth.scanner:scanner.py:586 hci0 (AA:BB:CC:DD:EE:FF): Force stopping bluetooth discovery 148s ERROR bleak_retry_connector.bluez:bluez.py:324 Failed to stop discovery for hci0 because no manager 148s DEBUG habluetooth.scanner:scanner.py:555 hci0 (AA:BB:CC:DD:EE:FF): adapter stopped responding; executing reset 148s DEBUG habluetooth.scanner:scanner.py:557 hci0 (AA:BB:CC:DD:EE:FF): adapter reset result: True 148s DEBUG habluetooth.scanner:scanner.py:434 hci0 (AA:BB:CC:DD:EE:FF): BleakError while starting bluetooth; attempt: (2/4): org.bluez.Error.InProgress 148s Traceback (most recent call last): 148s File "/usr/lib/python3/dist-packages/habluetooth/scanner.py", line 344, in _async_start_attempt 148s await self.scanner.start() 148s File "/tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/test_scanner.py", line 601, in start 148s raise BleakError("org.bluez.Error.InProgress") 148s bleak.exc.BleakError: org.bluez.Error.InProgress 148s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 148s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (3/4) 148s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 148s DEBUG habluetooth.scanner:scanner.py:586 hci0 (AA:BB:CC:DD:EE:FF): Force stopping bluetooth discovery 148s ERROR bleak_retry_connector.bluez:bluez.py:324 Failed to stop discovery for hci0 because no manager 148s DEBUG habluetooth.scanner:scanner.py:434 hci0 (AA:BB:CC:DD:EE:FF): BleakError while starting bluetooth; attempt: (3/4): org.bluez.Error.InProgress 148s Traceback (most recent call last): 148s File "/usr/lib/python3/dist-packages/habluetooth/scanner.py", line 344, in _async_start_attempt 148s await self.scanner.start() 148s File "/tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/test_scanner.py", line 603, in start 148s raise BleakError("org.bluez.Error.InProgress") 148s bleak.exc.BleakError: org.bluez.Error.InProgress 148s DEBUG habluetooth.scanner:scanner.py:324 hci0 (AA:BB:CC:DD:EE:FF): Falling back to passive scanning mode after active scanning failed (4/4) 148s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'passive', 'adapter': 'hci0', 'bluez': } 148s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (4/4) 148s WARNING habluetooth.scanner:scanner.py:411 hci0 (AA:BB:CC:DD:EE:FF): Successful fall-back to passive scanning mode after active scanning failed (4/4) 148s DEBUG habluetooth.scanner:scanner.py:418 hci0 (AA:BB:CC:DD:EE:FF): Success while starting bluetooth; attempt: (4/4) 148s DEBUG bleak_retry_connector:__init__.py:639 Failed to restore discoveries for hci0 148s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 148s PASSED [ 66%] 148s tests/test_scanner.py::test_restart_takes_longer_than_watchdog_time 148s -------------------------------- live log setup -------------------------------- 148s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 148s -------------------------------- live log call --------------------------------- 148s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 148s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (1/4) 148s DEBUG habluetooth.scanner:scanner.py:418 hci0 (AA:BB:CC:DD:EE:FF): Success while starting bluetooth; attempt: (1/4) 148s DEBUG bleak_retry_connector:__init__.py:639 Failed to restore discoveries for hci0 148s DEBUG habluetooth.base_scanner:base_scanner.py:210 hci0 (AA:BB:CC:DD:EE:FF): Scanner watchdog time_since_last_detection: 120.00000000000001 148s DEBUG habluetooth.scanner:scanner.py:517 hci0 (AA:BB:CC:DD:EE:FF): Bluetooth scanner has gone quiet for 120.00000000000001s, restarting 148s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 148s DEBUG habluetooth.scanner:scanner.py:555 hci0 (AA:BB:CC:DD:EE:FF): adapter stopped responding; executing reset 148s DEBUG habluetooth.scanner:scanner.py:557 hci0 (AA:BB:CC:DD:EE:FF): adapter reset result: True 148s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 148s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (1/4) 148s DEBUG habluetooth.base_scanner:base_scanner.py:210 hci0 (AA:BB:CC:DD:EE:FF): Scanner watchdog time_since_last_detection: 120.00000000000001 148s DEBUG habluetooth.scanner:scanner.py:512 hci0 (AA:BB:CC:DD:EE:FF): Scanner is already restarting, deferring restart 148s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 148s DEBUG habluetooth.scanner:scanner.py:426 hci0 (AA:BB:CC:DD:EE:FF): TimeoutError while starting bluetooth; attempt: (1/4) 148s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 148s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (2/4) 148s DEBUG habluetooth.scanner:scanner.py:418 hci0 (AA:BB:CC:DD:EE:FF): Success while starting bluetooth; attempt: (2/4) 148s DEBUG bleak_retry_connector:__init__.py:639 Failed to restore discoveries for hci0 148s ERROR asyncio:base_events.py:1875 Future exception was never retrieved 148s future: 148s habluetooth.scanner._AbortStartError 148s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 148s PASSED [ 67%] 148s tests/test_scanner.py::test_setup_and_stop_macos SKIPPED (condition:...) [ 68%] 148s tests/test_scanner.py::test_adapter_init_fails_fallback_to_passive 148s -------------------------------- live log setup -------------------------------- 148s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 148s -------------------------------- live log call --------------------------------- 148s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 148s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (1/4) 148s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 148s DEBUG habluetooth.scanner:scanner.py:402 hci0 (AA:BB:CC:DD:EE:FF): Waiting for adapter to initialize; attempt (1/4) 148s DEBUG habluetooth.scanner:scanner.py:434 hci0 (AA:BB:CC:DD:EE:FF): BleakError while starting bluetooth; attempt: (1/4): org.freedesktop.DBus.Error.UnknownObject 148s Traceback (most recent call last): 148s File "/usr/lib/python3/dist-packages/habluetooth/scanner.py", line 344, in _async_start_attempt 148s await self.scanner.start() 148s File "/tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/test_scanner.py", line 780, in start 148s raise BleakError("org.freedesktop.DBus.Error.UnknownObject") 148s bleak.exc.BleakError: org.freedesktop.DBus.Error.UnknownObject 148s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 148s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (2/4) 148s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 148s DEBUG habluetooth.scanner:scanner.py:586 hci0 (AA:BB:CC:DD:EE:FF): Force stopping bluetooth discovery 148s ERROR bleak_retry_connector.bluez:bluez.py:324 Failed to stop discovery for hci0 because no manager 148s DEBUG habluetooth.scanner:scanner.py:555 hci0 (AA:BB:CC:DD:EE:FF): adapter stopped responding; executing reset 148s DEBUG habluetooth.scanner:scanner.py:557 hci0 (AA:BB:CC:DD:EE:FF): adapter reset result: True 148s DEBUG habluetooth.scanner:scanner.py:434 hci0 (AA:BB:CC:DD:EE:FF): BleakError while starting bluetooth; attempt: (2/4): org.bluez.Error.InProgress 148s Traceback (most recent call last): 148s File "/usr/lib/python3/dist-packages/habluetooth/scanner.py", line 344, in _async_start_attempt 148s await self.scanner.start() 148s File "/tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/test_scanner.py", line 782, in start 148s raise BleakError("org.bluez.Error.InProgress") 148s bleak.exc.BleakError: org.bluez.Error.InProgress 148s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 148s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (3/4) 148s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 148s DEBUG habluetooth.scanner:scanner.py:586 hci0 (AA:BB:CC:DD:EE:FF): Force stopping bluetooth discovery 148s ERROR bleak_retry_connector.bluez:bluez.py:324 Failed to stop discovery for hci0 because no manager 148s DEBUG habluetooth.scanner:scanner.py:434 hci0 (AA:BB:CC:DD:EE:FF): BleakError while starting bluetooth; attempt: (3/4): org.bluez.Error.InProgress 148s Traceback (most recent call last): 148s File "/usr/lib/python3/dist-packages/habluetooth/scanner.py", line 344, in _async_start_attempt 148s await self.scanner.start() 148s File "/tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/test_scanner.py", line 784, in start 148s raise BleakError("org.bluez.Error.InProgress") 148s bleak.exc.BleakError: org.bluez.Error.InProgress 148s DEBUG habluetooth.scanner:scanner.py:324 hci0 (AA:BB:CC:DD:EE:FF): Falling back to passive scanning mode after active scanning failed (4/4) 148s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'passive', 'adapter': 'hci0', 'bluez': } 148s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (4/4) 148s WARNING habluetooth.scanner:scanner.py:411 hci0 (AA:BB:CC:DD:EE:FF): Successful fall-back to passive scanning mode after active scanning failed (4/4) 148s DEBUG habluetooth.scanner:scanner.py:418 hci0 (AA:BB:CC:DD:EE:FF): Success while starting bluetooth; attempt: (4/4) 148s DEBUG bleak_retry_connector:__init__.py:639 Failed to restore discoveries for hci0 148s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 148s PASSED [ 70%] 148s tests/test_storage.py::test_discovered_device_advertisement_data_to_dict PASSED [ 71%] 148s tests/test_storage.py::test_discovered_device_advertisement_data_from_dict PASSED [ 72%] 148s tests/test_storage.py::test_expire_stale_scanner_discovered_device_advertisement_data 148s -------------------------------- live log call --------------------------------- 148s DEBUG habluetooth.storage:storage.py:122 Loaded 1 fresh discovered devices for myscanner 148s DEBUG habluetooth.storage:storage.py:122 Loaded 0 fresh discovered devices for all_expired 148s PASSED [ 73%] 148s tests/test_storage.py::test_expire_future_discovered_device_advertisement_data 148s -------------------------------- live log call --------------------------------- 148s DEBUG habluetooth.storage:storage.py:122 Loaded 1 fresh discovered devices for myscanner 148s WARNING habluetooth.storage:storage.py:107 Discarding timestamp 1765990548.3831062 for CC:DD:EE:FF:AA:BB on scanner all_future as it is the future (now = 1764990548.383114) 148s DEBUG habluetooth.storage:storage.py:122 Loaded 0 fresh discovered devices for all_future 148s PASSED [ 74%] 148s tests/test_storage.py::test_discovered_device_advertisement_data_from_dict_corrupt 148s -------------------------------- live log call --------------------------------- 148s ERROR habluetooth.storage:storage.py:147 Error deserializing discovered_device_advertisement_data, adapter startup will be slow: BLEDevice.__init__() missing 1 required positional argument: 'name' 148s Traceback (most recent call last): 148s File "/usr/lib/python3/dist-packages/habluetooth/storage.py", line 138, in discovered_device_advertisement_data_from_dict 148s _deserialize_discovered_device_advertisement_datas( 148s ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~^ 148s data[DISCOVERED_DEVICE_ADVERTISEMENT_DATAS] 148s ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ 148s ), 148s ^ 148s File "/usr/lib/python3/dist-packages/habluetooth/storage.py", line 198, in _deserialize_discovered_device_advertisement_datas 148s _ble_device_from_dict(device_advertisement_data["device"]), 148s ~~~~~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ 148s File "/usr/lib/python3/dist-packages/habluetooth/storage.py", line 215, in _ble_device_from_dict 148s return BLEDevice(**device_data) 148s TypeError: BLEDevice.__init__() missing 1 required positional argument: 'name' 148s PASSED [ 75%] 148s tests/test_storage.py::test_backward_compatibility_rssi_in_device_dict PASSED [ 76%] 148s tests/test_wrappers.py::test_test_switch_adapters_when_out_of_slots 148s -------------------------------- live log setup -------------------------------- 148s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 148s -------------------------------- live log call --------------------------------- 148s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (00:00:00:00:00:01) 148s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci1 (00:00:00:00:00:02) 148s DEBUG habluetooth.wrappers:wrappers.py:279 00:00:00:00:00:01: Looking for backend to connect 148s INFO habluetooth.wrappers:wrappers.py:383 00:00:00:00:00:01 - any: Found 2 connection path(s), preferred order: hci0 (00:00:00:00:00:01) (RSSI=-60) (failures=0) (in_progress=0) (score=-60), hci1 (00:00:00:00:00:02) (RSSI=-80) (failures=0) (in_progress=0) (score=-80) 148s DEBUG habluetooth.wrappers:wrappers.py:305 00:00:00:00:00:01 - any -> /org/bluez/hci0: Connecting via hci0 (00:00:00:00:00:01) (last rssi: -60) 148s DEBUG habluetooth.wrappers:wrappers.py:326 00:00:00:00:00:01 - any -> /org/bluez/hci0: Connected via hci0 (00:00:00:00:00:01) (last rssi: -60) 148s DEBUG habluetooth.wrappers:wrappers.py:279 00:00:00:00:00:02: Looking for backend to connect 148s INFO habluetooth.wrappers:wrappers.py:383 00:00:00:00:00:02 - any: Found 2 connection path(s), preferred order: hci0 (00:00:00:00:00:01) (RSSI=-60) (failures=0) (in_progress=0) (score=-60), hci1 (00:00:00:00:00:02) (RSSI=-80) (failures=0) (in_progress=0) (score=-80) 148s DEBUG habluetooth.wrappers:wrappers.py:279 00:00:00:00:00:03: Looking for backend to connect 148s INFO habluetooth.wrappers:wrappers.py:383 00:00:00:00:00:03 - any: Found 2 connection path(s), preferred order: hci0 (00:00:00:00:00:01) (RSSI=-60) (failures=0) (in_progress=0) (score=-60), hci1 (00:00:00:00:00:02) (RSSI=-80) (failures=0) (in_progress=0) (score=-80) 148s DEBUG habluetooth.wrappers:wrappers.py:305 00:00:00:00:00:03 - any -> /org/bluez/hci1: Connecting via hci1 (00:00:00:00:00:02) (last rssi: -80) 148s DEBUG habluetooth.wrappers:wrappers.py:326 00:00:00:00:00:03 - any -> /org/bluez/hci1: Connected via hci1 (00:00:00:00:00:02) (last rssi: -80) 148s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (00:00:00:00:00:01) 148s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci1 (00:00:00:00:00:02) 148s PASSED [ 77%] 148s tests/test_wrappers.py::test_release_slot_on_connect_failure 148s -------------------------------- live log setup -------------------------------- 148s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 148s -------------------------------- live log call --------------------------------- 148s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (00:00:00:00:00:01) 148s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci1 (00:00:00:00:00:02) 148s DEBUG habluetooth.wrappers:wrappers.py:279 00:00:00:00:00:01: Looking for backend to connect 148s INFO habluetooth.wrappers:wrappers.py:383 00:00:00:00:00:01 - any: Found 2 connection path(s), preferred order: hci0 (00:00:00:00:00:01) (RSSI=-60) (failures=0) (in_progress=0) (score=-60), hci1 (00:00:00:00:00:02) (RSSI=-80) (failures=0) (in_progress=0) (score=-80) 148s DEBUG habluetooth.wrappers:wrappers.py:305 00:00:00:00:00:01 - any -> /org/bluez/hci0: Connecting via hci0 (00:00:00:00:00:01) (last rssi: -60) 148s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (00:00:00:00:00:01) 148s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci1 (00:00:00:00:00:02) 148s PASSED [ 78%] 148s tests/test_wrappers.py::test_release_slot_on_connect_exception 148s -------------------------------- live log setup -------------------------------- 148s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 148s -------------------------------- live log call --------------------------------- 148s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (00:00:00:00:00:01) 148s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci1 (00:00:00:00:00:02) 148s DEBUG habluetooth.wrappers:wrappers.py:279 00:00:00:00:00:01: Looking for backend to connect 148s INFO habluetooth.wrappers:wrappers.py:383 00:00:00:00:00:01 - any: Found 2 connection path(s), preferred order: hci0 (00:00:00:00:00:01) (RSSI=-60) (failures=0) (in_progress=0) (score=-60), hci1 (00:00:00:00:00:02) (RSSI=-80) (failures=0) (in_progress=0) (score=-80) 148s DEBUG habluetooth.wrappers:wrappers.py:305 00:00:00:00:00:01 - any -> /org/bluez/hci0: Connecting via hci0 (00:00:00:00:00:01) (last rssi: -60) 148s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (00:00:00:00:00:01) 148s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci1 (00:00:00:00:00:02) 148s PASSED [ 80%] 148s tests/test_wrappers.py::test_switch_adapters_on_failure 148s -------------------------------- live log setup -------------------------------- 148s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 148s -------------------------------- live log call --------------------------------- 148s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (00:00:00:00:00:01) 148s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci1 (00:00:00:00:00:02) 148s DEBUG habluetooth.wrappers:wrappers.py:279 00:00:00:00:00:01: Looking for backend to connect 148s INFO habluetooth.wrappers:wrappers.py:383 00:00:00:00:00:01 - any: Found 2 connection path(s), preferred order: hci0 (00:00:00:00:00:01) (RSSI=-60) (failures=0) (in_progress=0) (score=-60), hci1 (00:00:00:00:00:02) (RSSI=-80) (failures=0) (in_progress=0) (score=-80) 148s DEBUG habluetooth.wrappers:wrappers.py:305 00:00:00:00:00:01 - any -> /org/bluez/hci0: Connecting via hci0 (00:00:00:00:00:01) (last rssi: -60) 148s DEBUG habluetooth.wrappers:wrappers.py:279 00:00:00:00:00:01: Looking for backend to connect 148s INFO habluetooth.wrappers:wrappers.py:383 00:00:00:00:00:01 - any: Found 2 connection path(s), preferred order: hci0 (00:00:00:00:00:01) (RSSI=-60) (failures=1) (in_progress=0) (score=-60.0), hci1 (00:00:00:00:00:02) (RSSI=-80) (failures=0) (in_progress=0) (score=-80) 148s DEBUG habluetooth.wrappers:wrappers.py:305 00:00:00:00:00:01 - any -> /org/bluez/hci0: Connecting via hci0 (00:00:00:00:00:01) (last rssi: -60) 148s DEBUG habluetooth.wrappers:wrappers.py:279 00:00:00:00:00:01: Looking for backend to connect 148s INFO habluetooth.wrappers:wrappers.py:383 00:00:00:00:00:01 - any: Found 2 connection path(s), preferred order: hci1 (00:00:00:00:00:02) (RSSI=-80) (failures=0) (in_progress=0) (score=-80), hci0 (00:00:00:00:00:01) (RSSI=-60) (failures=2) (in_progress=0) (score=-60.0) 148s DEBUG habluetooth.wrappers:wrappers.py:305 00:00:00:00:00:01 - any -> /org/bluez/hci1: Connecting via hci1 (00:00:00:00:00:02) (last rssi: -80) 148s DEBUG habluetooth.wrappers:wrappers.py:326 00:00:00:00:00:01 - any -> /org/bluez/hci1: Connected via hci1 (00:00:00:00:00:02) (last rssi: -80) 148s DEBUG habluetooth.wrappers:wrappers.py:279 00:00:00:00:00:01: Looking for backend to connect 148s INFO habluetooth.wrappers:wrappers.py:383 00:00:00:00:00:01 - any: Found 2 connection path(s), preferred order: hci1 (00:00:00:00:00:02) (RSSI=-80) (failures=0) (in_progress=0) (score=-80), hci0 (00:00:00:00:00:01) (RSSI=-60) (failures=2) (in_progress=0) (score=-60.0) 148s DEBUG habluetooth.wrappers:wrappers.py:305 00:00:00:00:00:01 - any -> /org/bluez/hci1: Connecting via hci1 (00:00:00:00:00:02) (last rssi: -80) 148s DEBUG habluetooth.wrappers:wrappers.py:326 00:00:00:00:00:01 - any -> /org/bluez/hci1: Connected via hci1 (00:00:00:00:00:02) (last rssi: -80) 148s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (00:00:00:00:00:01) 148s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci1 (00:00:00:00:00:02) 148s PASSED [ 81%] 148s tests/test_wrappers.py::test_switch_adapters_on_connecting 148s -------------------------------- live log setup -------------------------------- 148s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 148s -------------------------------- live log call --------------------------------- 148s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (00:00:00:00:00:01) 148s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci1 (00:00:00:00:00:02) 148s DEBUG habluetooth.wrappers:wrappers.py:279 00:00:00:00:00:01: Looking for backend to connect 148s INFO habluetooth.wrappers:wrappers.py:383 00:00:00:00:00:01 - any: Found 2 connection path(s), preferred order: hci0 (00:00:00:00:00:01) (RSSI=-60) (failures=0) (in_progress=0) (score=-60), hci1 (00:00:00:00:00:02) (RSSI=-80) (failures=0) (in_progress=0) (score=-80) 148s DEBUG habluetooth.wrappers:wrappers.py:305 00:00:00:00:00:01 - any -> /org/bluez/hci0: Connecting via hci0 (00:00:00:00:00:01) (last rssi: -60) 148s DEBUG habluetooth.wrappers:wrappers.py:279 00:00:00:00:00:01: Looking for backend to connect 148s INFO habluetooth.wrappers:wrappers.py:383 00:00:00:00:00:01 - any: Found 2 connection path(s), preferred order: hci1 (00:00:00:00:00:02) (RSSI=-80) (failures=0) (in_progress=0) (score=-80), hci0 (00:00:00:00:00:01) (RSSI=-60) (failures=0) (in_progress=1) (score=-60.0) 148s DEBUG habluetooth.wrappers:wrappers.py:305 00:00:00:00:00:01 - any -> /org/bluez/hci1: Connecting via hci1 (00:00:00:00:00:02) (last rssi: -80) 148s DEBUG habluetooth.wrappers:wrappers.py:326 00:00:00:00:00:01 - any -> /org/bluez/hci1: Connected via hci1 (00:00:00:00:00:02) (last rssi: -80) 148s DEBUG habluetooth.wrappers:wrappers.py:326 00:00:00:00:00:01 - any -> /org/bluez/hci0: Connected via hci0 (00:00:00:00:00:01) (last rssi: -60) 148s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (00:00:00:00:00:01) 148s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci1 (00:00:00:00:00:02) 148s PASSED [ 82%] 148s tests/test_wrappers.py::test_single_adapter_connection_history 148s -------------------------------- live log setup -------------------------------- 148s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 148s -------------------------------- live log call --------------------------------- 148s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (AA:BB:CC:DD:EE:00) 148s DEBUG habluetooth.wrappers:wrappers.py:279 00:00:00:00:00:11: Looking for backend to connect 148s INFO habluetooth.wrappers:wrappers.py:383 00:00:00:00:00:11 - any: Found 1 connection path(s), preferred order: hci0 (AA:BB:CC:DD:EE:00) (RSSI=-60) (failures=0) (in_progress=0) (score=-60) 148s DEBUG habluetooth.wrappers:wrappers.py:305 00:00:00:00:00:11 - any -> /org/bluez/hci0: Connecting via hci0 (AA:BB:CC:DD:EE:00) (last rssi: -60) 148s DEBUG habluetooth.wrappers:wrappers.py:326 00:00:00:00:00:11 - any -> /org/bluez/hci0: Connected via hci0 (AA:BB:CC:DD:EE:00) (last rssi: -60) 148s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (AA:BB:CC:DD:EE:00) 148s PASSED [ 83%] 148s tests/test_wrappers.py::test_passing_subclassed_str_as_address 148s -------------------------------- live log setup -------------------------------- 148s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 148s -------------------------------- live log call --------------------------------- 148s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (00:00:00:00:00:01) 148s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci1 (00:00:00:00:00:02) 148s DEBUG habluetooth.wrappers:wrappers.py:279 00:00:00:00:00:01: Looking for backend to connect 148s INFO habluetooth.wrappers:wrappers.py:383 00:00:00:00:00:01 - any: Found 2 connection path(s), preferred order: hci0 (00:00:00:00:00:01) (RSSI=-60) (failures=0) (in_progress=0) (score=-60), hci1 (00:00:00:00:00:02) (RSSI=-80) (failures=0) (in_progress=0) (score=-80) 148s DEBUG habluetooth.wrappers:wrappers.py:305 00:00:00:00:00:01 - any -> /org/bluez/hci0: Connecting via hci0 (00:00:00:00:00:01) (last rssi: -60) 148s DEBUG habluetooth.wrappers:wrappers.py:326 00:00:00:00:00:01 - any -> /org/bluez/hci0: Connected via hci0 (00:00:00:00:00:01) (last rssi: -60) 148s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (00:00:00:00:00:01) 148s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci1 (00:00:00:00:00:02) 148s PASSED [ 84%] 148s tests/test_wrappers.py::test_find_device_by_address 148s -------------------------------- live log setup -------------------------------- 148s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 148s -------------------------------- live log call --------------------------------- 148s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (00:00:00:00:00:01) 148s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci1 (00:00:00:00:00:02) 148s PASSED [ 85%] 148s tests/test_wrappers.py::test_discover 148s -------------------------------- live log setup -------------------------------- 148s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 148s -------------------------------- live log call --------------------------------- 148s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (00:00:00:00:00:01) 148s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci1 (00:00:00:00:00:02) 148s PASSED [ 86%] 148s tests/test_wrappers.py::test_raise_after_shutdown 148s -------------------------------- live log setup -------------------------------- 148s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 148s -------------------------------- live log call --------------------------------- 148s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (00:00:00:00:00:01) 148s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci1 (00:00:00:00:00:02) 148s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (00:00:00:00:00:01) 148s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci1 (00:00:00:00:00:02) 148s PASSED [ 87%] 148s tests/test_wrappers.py::test_wrapped_instance_with_filter 148s -------------------------------- live log setup -------------------------------- 148s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 148s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (AA:BB:CC:DD:EE:00) 148s PASSED [ 88%] 148s ------------------------------ live log teardown ------------------------------- 148s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (AA:BB:CC:DD:EE:00) 148s 148s tests/test_wrappers.py::test_wrapped_instance_with_service_uuids 148s -------------------------------- live log setup -------------------------------- 148s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 148s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (AA:BB:CC:DD:EE:00) 148s PASSED [ 90%] 148s ------------------------------ live log teardown ------------------------------- 148s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (AA:BB:CC:DD:EE:00) 148s 148s tests/test_wrappers.py::test_wrapped_instance_with_service_uuids_with_coro_callback 148s -------------------------------- live log setup -------------------------------- 148s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 148s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (AA:BB:CC:DD:EE:00) 148s PASSED [ 91%] 148s ------------------------------ live log teardown ------------------------------- 148s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (AA:BB:CC:DD:EE:00) 148s 148s tests/test_wrappers.py::test_wrapped_instance_with_broken_callbacks 148s -------------------------------- live log setup -------------------------------- 148s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 148s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (AA:BB:CC:DD:EE:00) 148s PASSED [ 92%] 148s ------------------------------ live log teardown ------------------------------- 148s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (AA:BB:CC:DD:EE:00) 148s 148s tests/test_wrappers.py::test_wrapped_instance_changes_uuids 148s -------------------------------- live log setup -------------------------------- 148s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 148s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (AA:BB:CC:DD:EE:00) 148s PASSED [ 93%] 148s ------------------------------ live log teardown ------------------------------- 148s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (AA:BB:CC:DD:EE:00) 148s 148s tests/test_wrappers.py::test_wrapped_instance_changes_filters 148s -------------------------------- live log setup -------------------------------- 148s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 148s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (AA:BB:CC:DD:EE:00) 148s PASSED [ 94%] 148s ------------------------------ live log teardown ------------------------------- 148s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (AA:BB:CC:DD:EE:00) 148s 148s tests/test_wrappers.py::test_wrapped_instance_unsupported_filter 148s -------------------------------- live log setup -------------------------------- 148s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 148s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (AA:BB:CC:DD:EE:00) 148s -------------------------------- live log call --------------------------------- 148s WARNING habluetooth.wrappers:wrappers.py:120 Only UUIDs filters are supported 148s PASSED [ 95%] 148s ------------------------------ live log teardown ------------------------------- 148s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (AA:BB:CC:DD:EE:00) 148s 148s tests/test_wrappers.py::test_client_with_services_parameter 148s -------------------------------- live log setup -------------------------------- 148s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 148s -------------------------------- live log call --------------------------------- 148s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (00:00:00:00:00:01) 148s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci1 (00:00:00:00:00:02) 148s DEBUG habluetooth.wrappers:wrappers.py:279 00:00:00:00:00:01: Looking for backend to connect 148s INFO habluetooth.wrappers:wrappers.py:383 00:00:00:00:00:01 - any: Found 2 connection path(s), preferred order: hci0 (00:00:00:00:00:01) (RSSI=-60) (failures=0) (in_progress=0) (score=-60), hci1 (00:00:00:00:00:02) (RSSI=-80) (failures=0) (in_progress=0) (score=-80) 148s DEBUG habluetooth.wrappers:wrappers.py:305 00:00:00:00:00:01 - any -> /org/bluez/hci0: Connecting via hci0 (00:00:00:00:00:01) (last rssi: -60) 148s DEBUG habluetooth.wrappers:wrappers.py:326 00:00:00:00:00:01 - any -> /org/bluez/hci0: Connected via hci0 (00:00:00:00:00:01) (last rssi: -60) 148s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (00:00:00:00:00:01) 148s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci1 (00:00:00:00:00:02) 148s PASSED [ 96%] 148s tests/test_wrappers.py::test_client_with_pair_parameter 148s -------------------------------- live log setup -------------------------------- 148s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 148s -------------------------------- live log call --------------------------------- 148s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (00:00:00:00:00:01) 148s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci1 (00:00:00:00:00:02) 148s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (00:00:00:00:00:01) 148s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci1 (00:00:00:00:00:02) 148s PASSED [ 97%] 148s tests/test_wrappers.py::test_client_services_normalization 148s -------------------------------- live log setup -------------------------------- 148s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 148s -------------------------------- live log call --------------------------------- 148s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (00:00:00:00:00:01) 148s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci1 (00:00:00:00:00:02) 148s DEBUG habluetooth.wrappers:wrappers.py:279 00:00:00:00:00:01: Looking for backend to connect 148s INFO habluetooth.wrappers:wrappers.py:383 00:00:00:00:00:01 - any: Found 2 connection path(s), preferred order: hci0 (00:00:00:00:00:01) (RSSI=-60) (failures=0) (in_progress=0) (score=-60), hci1 (00:00:00:00:00:02) (RSSI=-80) (failures=0) (in_progress=0) (score=-80) 148s DEBUG habluetooth.wrappers:wrappers.py:305 00:00:00:00:00:01 - any -> /org/bluez/hci0: Connecting via hci0 (00:00:00:00:00:01) (last rssi: -60) 148s DEBUG habluetooth.wrappers:wrappers.py:326 00:00:00:00:00:01 - any -> /org/bluez/hci0: Connected via hci0 (00:00:00:00:00:01) (last rssi: -60) 148s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (00:00:00:00:00:01) 148s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci1 (00:00:00:00:00:02) 148s PASSED [ 98%] 148s tests/test_wrappers.py::test_client_with_none_services 148s -------------------------------- live log setup -------------------------------- 148s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 148s -------------------------------- live log call --------------------------------- 148s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (00:00:00:00:00:01) 148s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci1 (00:00:00:00:00:02) 148s DEBUG habluetooth.wrappers:wrappers.py:279 00:00:00:00:00:01: Looking for backend to connect 148s INFO habluetooth.wrappers:wrappers.py:383 00:00:00:00:00:01 - any: Found 2 connection path(s), preferred order: hci0 (00:00:00:00:00:01) (RSSI=-60) (failures=0) (in_progress=0) (score=-60), hci1 (00:00:00:00:00:02) (RSSI=-80) (failures=0) (in_progress=0) (score=-80) 148s DEBUG habluetooth.wrappers:wrappers.py:305 00:00:00:00:00:01 - any -> /org/bluez/hci0: Connecting via hci0 (00:00:00:00:00:01) (last rssi: -60) 148s DEBUG habluetooth.wrappers:wrappers.py:326 00:00:00:00:00:01 - any -> /org/bluez/hci0: Connected via hci0 (00:00:00:00:00:01) (last rssi: -60) 148s DEBUG habluetooth.wrappers:wrappers.py:279 00:00:00:00:00:01: Looking for backend to connect 148s INFO habluetooth.wrappers:wrappers.py:383 00:00:00:00:00:01 - any: Found 2 connection path(s), preferred order: hci0 (00:00:00:00:00:01) (RSSI=-60) (failures=0) (in_progress=0) (score=-60), hci1 (00:00:00:00:00:02) (RSSI=-80) (failures=0) (in_progress=0) (score=-80) 148s DEBUG habluetooth.wrappers:wrappers.py:305 00:00:00:00:00:01 - any -> /org/bluez/hci0: Connecting via hci0 (00:00:00:00:00:01) (last rssi: -60) 148s DEBUG habluetooth.wrappers:wrappers.py:326 00:00:00:00:00:01 - any -> /org/bluez/hci0: Connected via hci0 (00:00:00:00:00:01) (last rssi: -60) 148s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (00:00:00:00:00:01) 148s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci1 (00:00:00:00:00:02) 148s PASSED [100%] 148s ------------------------------ live log teardown ------------------------------- 148s DEBUG habluetooth.manager:manager.py:322 Stopping bluetooth manager 148s 148s 148s =============================== warnings summary =============================== 148s tests/test_base_scanner.py::test_remote_scanner[None] 148s /usr/lib/python3/dist-packages/pytest_asyncio/plugin.py:1177: DeprecationWarning: 'asyncio.get_event_loop_policy' is deprecated and slated for removal in Python 3.16 148s return asyncio.get_event_loop_policy() 148s 148s tests/test_base_scanner.py: 10 warnings 148s tests/test_manager.py: 20 warnings 148s tests/test_scanner.py: 18 warnings 148s tests/test_wrappers.py: 21 warnings 148s /usr/lib/python3/dist-packages/pytest_asyncio/plugin.py:755: DeprecationWarning: 'asyncio.get_event_loop_policy' is deprecated and slated for removal in Python 3.16 148s old_loop_policy = asyncio.get_event_loop_policy() 148s 148s tests/test_base_scanner.py: 10 warnings 148s tests/test_manager.py: 20 warnings 148s tests/test_scanner.py: 18 warnings 148s tests/test_wrappers.py: 21 warnings 148s /usr/lib/python3/dist-packages/pytest_asyncio/plugin.py:760: DeprecationWarning: 'asyncio.set_event_loop_policy' is deprecated and slated for removal in Python 3.16 148s asyncio.set_event_loop_policy(policy) 148s 148s tests/test_base_scanner.py: 9 warnings 148s tests/test_manager.py: 20 warnings 148s tests/test_scanner.py: 18 warnings 148s tests/test_wrappers.py: 21 warnings 148s /usr/lib/python3/dist-packages/pytest_asyncio/plugin.py:856: DeprecationWarning: 'asyncio.get_event_loop_policy' is deprecated and slated for removal in Python 3.16 148s _restore_event_loop_policy(asyncio.get_event_loop_policy()), 148s 148s tests/test_base_scanner.py: 9 warnings 148s tests/test_manager.py: 20 warnings 148s tests/test_scanner.py: 18 warnings 148s tests/test_wrappers.py: 21 warnings 148s /usr/lib/python3/dist-packages/pytest_asyncio/plugin.py:1151: DeprecationWarning: 'asyncio.get_event_loop_policy' is deprecated and slated for removal in Python 3.16 148s loop = asyncio.get_event_loop_policy().new_event_loop() 148s 148s tests/test_base_scanner.py: 9 warnings 148s tests/test_manager.py: 20 warnings 148s tests/test_scanner.py: 18 warnings 148s tests/test_wrappers.py: 21 warnings 148s /usr/lib/python3/dist-packages/pytest_asyncio/plugin.py:871: DeprecationWarning: 'asyncio.get_event_loop_policy' is deprecated and slated for removal in Python 3.16 148s policy = asyncio.get_event_loop_policy() 148s 148s tests/test_base_scanner.py: 9 warnings 148s tests/test_manager.py: 3 warnings 148s tests/test_wrappers.py: 14 warnings 148s /tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/__init__.py:64: DeprecationWarning: Passing additional arguments for BLEDevice is deprecated and has no effect. 148s return BLEDevice(**new) 148s 148s tests/test_base_scanner.py: 9 warnings 148s tests/test_manager.py: 20 warnings 148s tests/test_scanner.py: 18 warnings 148s tests/test_wrappers.py: 22 warnings 148s /usr/lib/python3/dist-packages/pytest_asyncio/plugin.py:777: DeprecationWarning: 'asyncio.set_event_loop_policy' is deprecated and slated for removal in Python 3.16 148s asyncio.set_event_loop_policy(old_loop_policy) 148s 148s tests/test_base_scanner.py: 9 warnings 148s tests/test_manager.py: 20 warnings 148s tests/test_scanner.py: 18 warnings 148s tests/test_wrappers.py: 21 warnings 148s /usr/lib/python3/dist-packages/pytest_asyncio/plugin.py:924: DeprecationWarning: 'asyncio.get_event_loop_policy' is deprecated and slated for removal in Python 3.16 148s policy = asyncio.get_event_loop_policy() 148s 148s tests/test_base_scanner.py: 9 warnings 148s tests/test_manager.py: 20 warnings 148s tests/test_scanner.py: 18 warnings 148s tests/test_wrappers.py: 21 warnings 148s /usr/lib/python3/dist-packages/pytest_asyncio/plugin.py:948: DeprecationWarning: 'asyncio.set_event_loop_policy' is deprecated and slated for removal in Python 3.16 148s asyncio.set_event_loop_policy(previous_policy) 148s 148s tests/test_base_scanner.py: 9 warnings 148s tests/test_manager.py: 20 warnings 148s tests/test_scanner.py: 18 warnings 148s tests/test_wrappers.py: 21 warnings 148s /usr/lib/python3/dist-packages/pytest_asyncio/plugin.py:960: DeprecationWarning: 'asyncio.get_event_loop_policy' is deprecated and slated for removal in Python 3.16 148s policy = asyncio.get_event_loop_policy() 148s 148s tests/test_base_scanner.py::test_remote_scanner_expires_non_connectable 148s /tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/test_base_scanner.py:326: FutureWarning: BaseHaRemoteScanner._discovered_device_timestamps is deprecated and will be removed in a future version of habluetooth, use BaseHaRemoteScanner.discovered_device_timestamps instead 148s assert len(scanner._discovered_device_timestamps) == 1 148s 148s tests/test_base_scanner.py::test_remote_scanner_expires_non_connectable 148s /tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/test_base_scanner.py:358: FutureWarning: BaseHaRemoteScanner._discovered_device_timestamps is deprecated and will be removed in a future version of habluetooth, use BaseHaRemoteScanner.discovered_device_timestamps instead 148s assert len(scanner._discovered_device_timestamps) == 0 148s 148s tests/test_base_scanner.py::test_remote_scanner_expires_non_connectable 148s /tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/test_base_scanner.py:377: FutureWarning: BaseHaRemoteScanner._discovered_device_timestamps is deprecated and will be removed in a future version of habluetooth, use BaseHaRemoteScanner.discovered_device_timestamps instead 148s assert len(scanner._discovered_device_timestamps) == 0 148s 148s -- Docs: https://docs.pytest.org/en/stable/how-to/capture-warnings.html 148s ================= 89 passed, 1 skipped, 645 warnings in 9.64s ================== 148s I: pybuild base:317: cd /tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build; python3.13 -m pytest --no-cov --ignore=tests/test_benchmark_base_scanner.py 148s /usr/lib/python3/dist-packages/pytest_asyncio/plugin.py:207: PytestDeprecationWarning: The configuration option "asyncio_default_fixture_loop_scope" is unset. 148s The event loop scope for asynchronous fixtures will default to the fixture caching scope. Future versions of pytest-asyncio will default the loop scope for asynchronous fixtures to function scope. Set the default fixture loop scope explicitly in order to avoid unexpected behavior in the future. Valid fixture loop scopes are: "function", "class", "module", "package", "session" 148s 148s warnings.warn(PytestDeprecationWarning(_DEFAULT_FIXTURE_LOOP_SCOPE_UNSET)) 148s ============================= test session starts ============================== 148s platform linux -- Python 3.13.9, pytest-8.3.5, pluggy-1.6.0 -- /usr/bin/python3.13 148s cachedir: .pytest_cache 148s rootdir: /tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build 148s configfile: pyproject.toml 148s plugins: typeguard-4.4.2, asyncio-0.25.1, cov-5.0.0 148s asyncio: mode=Mode.STRICT, asyncio_default_fixture_loop_scope=None 149s collecting ... collected 90 items 149s 149s tests/test_base_scanner.py::test_remote_scanner[None] 149s -------------------------------- live log setup -------------------------------- 149s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 149s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 149s WARNING habluetooth.manager:manager.py:189 BluetoothManager: does not implement _discover_service_info, subclasses must implement this method to consume discovery data 149s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 149s -------------------------------- live log call --------------------------------- 149s DEBUG habluetooth.manager:manager.py:765 Registering scanner esp32 149s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner esp32 149s PASSED [ 1%] 149s tests/test_base_scanner.py::test_remote_scanner[w] 149s -------------------------------- live log setup -------------------------------- 149s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 149s -------------------------------- live log call --------------------------------- 149s DEBUG habluetooth.manager:manager.py:765 Registering scanner esp32 149s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner esp32 149s PASSED [ 2%] 149s tests/test_base_scanner.py::test_remote_scanner_expires_connectable 149s -------------------------------- live log setup -------------------------------- 149s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 149s -------------------------------- live log call --------------------------------- 149s DEBUG habluetooth.manager:manager.py:765 Registering scanner esp32 149s DEBUG habluetooth.base_scanner:base_scanner.py:210 esp32: Scanner watchdog time_since_last_detection: 196.00168162900002 149s DEBUG habluetooth.base_scanner:base_scanner.py:225 esp32: Bluetooth scanner has gone quiet for 196.00168162900002s, check logs on the scanner device for more information 149s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner esp32 149s PASSED [ 3%] 149s tests/test_base_scanner.py::test_remote_scanner_expires_non_connectable 149s -------------------------------- live log setup -------------------------------- 149s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 149s -------------------------------- live log call --------------------------------- 149s DEBUG habluetooth.manager:manager.py:765 Registering scanner esp32 149s DEBUG habluetooth.base_scanner:base_scanner.py:210 esp32: Scanner watchdog time_since_last_detection: 196.00491665599998 149s DEBUG habluetooth.base_scanner:base_scanner.py:225 esp32: Bluetooth scanner has gone quiet for 196.00491665599998s, check logs on the scanner device for more information 149s DEBUG habluetooth.base_scanner:base_scanner.py:210 esp32: Scanner watchdog time_since_last_detection: 901.004916656 149s DEBUG habluetooth.base_scanner:base_scanner.py:225 esp32: Bluetooth scanner has gone quiet for 901.004916656s, check logs on the scanner device for more information 149s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner esp32 149s PASSED [ 4%] 149s tests/test_base_scanner.py::test_base_scanner_connecting_behavior 149s -------------------------------- live log setup -------------------------------- 149s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 149s -------------------------------- live log call --------------------------------- 149s DEBUG habluetooth.manager:manager.py:765 Registering scanner esp32 149s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner esp32 149s PASSED [ 5%] 149s tests/test_base_scanner.py::test_scanner_stops_responding 149s -------------------------------- live log setup -------------------------------- 149s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 149s -------------------------------- live log call --------------------------------- 149s DEBUG habluetooth.manager:manager.py:765 Registering scanner esp32 149s DEBUG habluetooth.base_scanner:base_scanner.py:210 esp32: Scanner watchdog time_since_last_detection: 120.00380592700002 149s DEBUG habluetooth.base_scanner:base_scanner.py:225 esp32: Bluetooth scanner has gone quiet for 120.00380592700002s, check logs on the scanner device for more information 149s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner esp32 149s PASSED [ 6%] 149s tests/test_base_scanner.py::test_merge_manufacturer_data_history_existing 149s -------------------------------- live log setup -------------------------------- 149s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 149s -------------------------------- live log call --------------------------------- 149s DEBUG habluetooth.manager:manager.py:765 Registering scanner esp32 149s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner esp32 149s PASSED [ 7%] 149s tests/test_base_scanner.py::test_merge_manufacturer_data_history_new 149s -------------------------------- live log setup -------------------------------- 149s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 149s -------------------------------- live log call --------------------------------- 149s DEBUG habluetooth.manager:manager.py:765 Registering scanner esp32 149s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner esp32 149s PASSED [ 8%] 149s tests/test_base_scanner.py::test_filter_apple_data 149s -------------------------------- live log setup -------------------------------- 149s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 149s -------------------------------- live log call --------------------------------- 149s DEBUG habluetooth.manager:manager.py:765 Registering scanner esp32 149s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner esp32 149s PASSED [ 10%] 149s tests/test_base_scanner.py::test_connection_history_count_in_progress 149s -------------------------------- live log setup -------------------------------- 149s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (AA:BB:CC:DD:EE:00) 149s PASSED [ 11%] 149s ------------------------------ live log teardown ------------------------------- 149s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (AA:BB:CC:DD:EE:00) 149s 149s tests/test_base_scanner.py::test_connection_history_failure_count 149s -------------------------------- live log setup -------------------------------- 149s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (AA:BB:CC:DD:EE:00) 149s -------------------------------- live log call --------------------------------- 149s WARNING habluetooth.base_scanner:base_scanner.py:131 Removing a non-existing connecting hci0 (AA:BB:CC:DD:EE:00) 44:44:33:11:23:12 149s PASSED [ 12%] 149s ------------------------------ live log teardown ------------------------------- 149s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (AA:BB:CC:DD:EE:00) 149s 149s tests/test_init.py::test_create_scanner 149s -------------------------------- live log setup -------------------------------- 149s WARNING habluetooth.manager:manager.py:189 BluetoothManager: does not implement _discover_service_info, subclasses must implement this method to consume discovery data 149s PASSED [ 13%] 149s tests/test_init.py::test_create_remote_scanner PASSED [ 14%] 149s tests/test_init.py::test__async_on_advertisement PASSED [ 15%] 149s tests/test_init.py::test__async_on_advertisement_first PASSED [ 16%] 149s tests/test_init.py::test__async_on_advertisement_prefers_longest_local_name PASSED [ 17%] 149s tests/test_init.py::test_create_ha_scanner PASSED [ 18%] 149s tests/test_manager.py::test_async_recover_failed_adapters 149s -------------------------------- live log setup -------------------------------- 149s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 149s -------------------------------- live log call --------------------------------- 149s WARNING habluetooth.manager:manager.py:189 BluetoothManager: does not implement _discover_service_info, subclasses must implement this method to consume discovery data 149s PASSED [ 20%] 149s tests/test_manager.py::test_create_manager 149s -------------------------------- live log setup -------------------------------- 149s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 149s -------------------------------- live log call --------------------------------- 149s WARNING habluetooth.manager:manager.py:189 BluetoothManager: does not implement _discover_service_info, subclasses must implement this method to consume discovery data 149s PASSED [ 21%] 149s tests/test_manager.py::test_async_register_disappeared_callback 149s -------------------------------- live log setup -------------------------------- 149s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 149s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (AA:BB:CC:DD:EE:00) 149s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci1 (AA:BB:CC:DD:EE:11) 149s -------------------------------- live log call --------------------------------- 149s ERROR habluetooth.manager:manager.py:425 Error in disappeared callback 149s Traceback (most recent call last): 149s File "/usr/lib/python3/dist-packages/habluetooth/manager.py", line 423, in _async_check_unavailable 149s disappear_callback(address) 149s ~~~~~~~~~~~~~~~~~~^^^^^^^^^ 149s File "/tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/test_manager.py", line 188, in _failing_callback 149s raise ValueError("This is a test") 149s ValueError: This is a test 149s PASSED [ 22%] 149s ------------------------------ live log teardown ------------------------------- 149s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci1 (AA:BB:CC:DD:EE:11) 149s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (AA:BB:CC:DD:EE:00) 149s 149s tests/test_manager.py::test_async_register_allocation_callback 149s -------------------------------- live log setup -------------------------------- 149s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 149s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (AA:BB:CC:DD:EE:00) 149s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci1 (AA:BB:CC:DD:EE:11) 149s -------------------------------- live log call --------------------------------- 149s ERROR habluetooth.manager:manager.py:850 Error in allocation callback 149s Traceback (most recent call last): 149s File "/usr/lib/python3/dist-packages/habluetooth/manager.py", line 848, in async_on_allocation_changed 149s callback_(ha_slot_allocations) 149s ~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^ 149s File "/tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/test_manager.py", line 259, in _failing_callback 149s raise ValueError("This is a test") 149s ValueError: This is a test 149s ERROR habluetooth.manager:manager.py:850 Error in allocation callback 149s Traceback (most recent call last): 149s File "/usr/lib/python3/dist-packages/habluetooth/manager.py", line 848, in async_on_allocation_changed 149s callback_(ha_slot_allocations) 149s ~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^ 149s File "/tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/test_manager.py", line 259, in _failing_callback 149s raise ValueError("This is a test") 149s ValueError: This is a test 149s PASSED [ 23%] 149s ------------------------------ live log teardown ------------------------------- 149s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci1 (AA:BB:CC:DD:EE:11) 149s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (AA:BB:CC:DD:EE:00) 149s 149s tests/test_manager.py::test_async_register_allocation_callback_non_connectable 149s -------------------------------- live log setup -------------------------------- 149s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 149s DEBUG habluetooth.manager:manager.py:765 Registering scanner non connectable (AA:BB:CC:DD:EE:FF) 149s PASSED [ 24%] 149s ------------------------------ live log teardown ------------------------------- 149s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner non connectable (AA:BB:CC:DD:EE:FF) 149s 149s tests/test_manager.py::test_async_register_scanner_registration_callback 149s -------------------------------- live log setup -------------------------------- 149s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 149s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (AA:BB:CC:DD:EE:00) 149s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci1 (AA:BB:CC:DD:EE:11) 149s -------------------------------- live log call --------------------------------- 149s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci3 (AA:BB:CC:DD:EE:33) 149s ERROR habluetooth.manager:manager.py:867 Error in scanner callback 149s Traceback (most recent call last): 149s File "/usr/lib/python3/dist-packages/habluetooth/manager.py", line 865, in _async_on_scanner_registration 149s callback_(HaScannerRegistration(event, scanner)) 149s ~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ 149s File "/tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/test_manager.py", line 381, in _failing_callback 149s raise ValueError("This is a test") 149s ValueError: This is a test 149s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci3 (AA:BB:CC:DD:EE:33) 149s ERROR habluetooth.manager:manager.py:867 Error in scanner callback 149s Traceback (most recent call last): 149s File "/usr/lib/python3/dist-packages/habluetooth/manager.py", line 865, in _async_on_scanner_registration 149s callback_(HaScannerRegistration(event, scanner)) 149s ~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ 149s File "/tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/test_manager.py", line 381, in _failing_callback 149s raise ValueError("This is a test") 149s ValueError: This is a test 149s PASSED [ 25%] 149s ------------------------------ live log teardown ------------------------------- 149s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci1 (AA:BB:CC:DD:EE:11) 149s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (AA:BB:CC:DD:EE:00) 149s 149s tests/test_manager.py::test_async_register_scanner_with_connection_slots 149s -------------------------------- live log setup -------------------------------- 149s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 149s -------------------------------- live log call --------------------------------- 149s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci3 (AA:BB:CC:DD:EE:33) 149s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci3 (AA:BB:CC:DD:EE:33) 149s PASSED [ 26%] 149s tests/test_manager.py::test_diagnostics 149s -------------------------------- live log setup -------------------------------- 149s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 149s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (AA:BB:CC:DD:EE:00) 149s PASSED [ 27%] 149s ------------------------------ live log teardown ------------------------------- 149s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (AA:BB:CC:DD:EE:00) 149s 149s tests/test_manager.py::test_advertisements_do_not_switch_adapters_for_no_reason 149s -------------------------------- live log setup -------------------------------- 149s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 149s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (AA:BB:CC:DD:EE:00) 149s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci1 (AA:BB:CC:DD:EE:11) 149s PASSED [ 28%] 149s ------------------------------ live log teardown ------------------------------- 149s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci1 (AA:BB:CC:DD:EE:11) 149s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (AA:BB:CC:DD:EE:00) 149s 149s tests/test_manager.py::test_switching_adapters_based_on_rssi 149s -------------------------------- live log setup -------------------------------- 149s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 149s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (AA:BB:CC:DD:EE:00) 149s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci1 (AA:BB:CC:DD:EE:11) 149s -------------------------------- live log call --------------------------------- 149s DEBUG habluetooth.manager:manager.py:480 wohand_good_signal (44:44:33:11:23:45): Switching from hci0 (AA:BB:CC:DD:EE:00) [connectable] to hci1 (AA:BB:CC:DD:EE:11) [connectable] (new rssi:-60 - threshold:16 > old rssi:-100) 149s PASSED [ 30%] 149s ------------------------------ live log teardown ------------------------------- 149s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci1 (AA:BB:CC:DD:EE:11) 149s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (AA:BB:CC:DD:EE:00) 149s 149s tests/test_manager.py::test_switching_adapters_based_on_zero_rssi 149s -------------------------------- live log setup -------------------------------- 149s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 149s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (AA:BB:CC:DD:EE:00) 149s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci1 (AA:BB:CC:DD:EE:11) 149s -------------------------------- live log call --------------------------------- 149s DEBUG habluetooth.manager:manager.py:480 wohand_good_signal (44:44:33:11:23:45): Switching from hci0 (AA:BB:CC:DD:EE:00) [connectable] to hci1 (AA:BB:CC:DD:EE:11) [connectable] (new rssi:-60 - threshold:16 > old rssi:0) 149s PASSED [ 31%] 149s ------------------------------ live log teardown ------------------------------- 149s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci1 (AA:BB:CC:DD:EE:11) 149s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (AA:BB:CC:DD:EE:00) 149s 149s tests/test_manager.py::test_switching_adapters_based_on_stale 149s -------------------------------- live log setup -------------------------------- 149s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 149s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (AA:BB:CC:DD:EE:00) 149s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci1 (AA:BB:CC:DD:EE:11) 149s -------------------------------- live log call --------------------------------- 149s DEBUG habluetooth.manager:manager.py:463 wohand_poor_signal_hci1 (44:44:33:11:23:41): Switching from hci0 (AA:BB:CC:DD:EE:00) [connectable] to hci1 [connectable] (time elapsed:901.0 > stale seconds:900) 149s PASSED [ 32%] 149s ------------------------------ live log teardown ------------------------------- 149s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci1 (AA:BB:CC:DD:EE:11) 149s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (AA:BB:CC:DD:EE:00) 149s 149s tests/test_manager.py::test_switching_adapters_based_on_stale_with_discovered_interval 149s -------------------------------- live log setup -------------------------------- 149s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 149s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (AA:BB:CC:DD:EE:00) 149s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci1 (AA:BB:CC:DD:EE:11) 149s -------------------------------- live log call --------------------------------- 149s DEBUG habluetooth.manager:manager.py:463 wohand_poor_signal_hci1 (44:44:33:11:23:41): Switching from hci0 (AA:BB:CC:DD:EE:00) [connectable] to hci1 (AA:BB:CC:DD:EE:11) [connectable] (time elapsed:16.0 > stale seconds:15) 149s PASSED [ 33%] 149s ------------------------------ live log teardown ------------------------------- 149s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci1 (AA:BB:CC:DD:EE:11) 149s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (AA:BB:CC:DD:EE:00) 149s 149s tests/test_manager.py::test_switching_adapters_based_on_rssi_connectable_to_non_connectable 149s -------------------------------- live log setup -------------------------------- 149s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 149s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (AA:BB:CC:DD:EE:00) 149s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci1 (AA:BB:CC:DD:EE:11) 149s -------------------------------- live log call --------------------------------- 149s DEBUG habluetooth.manager:manager.py:480 wohand_good_signal (44:44:33:11:23:45): Switching from hci0 (AA:BB:CC:DD:EE:00) [connectable] to hci1 (new rssi:-60 - threshold:16 > old rssi:-100) 149s PASSED [ 34%] 149s ------------------------------ live log teardown ------------------------------- 149s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci1 (AA:BB:CC:DD:EE:11) 149s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (AA:BB:CC:DD:EE:00) 149s 149s tests/test_manager.py::test_connectable_advertisement_can_be_retrieved_best_path_is_non_connectable 149s -------------------------------- live log setup -------------------------------- 149s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 149s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (AA:BB:CC:DD:EE:00) 149s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci1 (AA:BB:CC:DD:EE:11) 149s PASSED [ 35%] 149s ------------------------------ live log teardown ------------------------------- 149s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci1 (AA:BB:CC:DD:EE:11) 149s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (AA:BB:CC:DD:EE:00) 149s 149s tests/test_manager.py::test_switching_adapters_when_one_goes_away 149s -------------------------------- live log setup -------------------------------- 149s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 149s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (AA:BB:CC:DD:EE:00) 149s -------------------------------- live log call --------------------------------- 149s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci2 149s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci2 149s PASSED [ 36%] 149s ------------------------------ live log teardown ------------------------------- 149s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (AA:BB:CC:DD:EE:00) 149s 149s tests/test_manager.py::test_switching_adapters_when_one_stop_scanning 149s -------------------------------- live log setup -------------------------------- 149s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 149s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (AA:BB:CC:DD:EE:00) 149s -------------------------------- live log call --------------------------------- 149s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci2 149s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci2 149s PASSED [ 37%] 149s ------------------------------ live log teardown ------------------------------- 149s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (AA:BB:CC:DD:EE:00) 149s 149s tests/test_manager.py::test_set_fallback_interval_small 149s -------------------------------- live log setup -------------------------------- 149s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 149s PASSED [ 38%] 149s tests/test_manager.py::test_set_fallback_interval_big 149s -------------------------------- live log setup -------------------------------- 149s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 149s PASSED [ 40%] 149s tests/test_manager.py::test_subclassing_bluetooth_manager 149s -------------------------------- live log setup -------------------------------- 149s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 149s -------------------------------- live log call --------------------------------- 149s WARNING habluetooth.manager:manager.py:189 TestBluetoothManager2: does not implement _discover_service_info, subclasses must implement this method to consume discovery data 149s PASSED [ 41%] 149s tests/test_models.py::test_model PASSED [ 42%] 149s tests/test_models.py::test_model_from_bleak PASSED [ 43%] 149s tests/test_models.py::test_model_from_scanner PASSED [ 44%] 149s tests/test_models.py::test_construct_service_info_bleak PASSED [ 45%] 149s tests/test_models.py::test_from_device_and_advertisement_data PASSED [ 46%] 149s tests/test_models.py::test_pyobjc_compat PASSED [ 47%] 149s tests/test_models.py::test_as_connectable PASSED [ 48%] 149s tests/test_scanner.py::test_empty_data_no_scanner 149s -------------------------------- live log setup -------------------------------- 149s WARNING habluetooth.manager:manager.py:189 BluetoothManager: does not implement _discover_service_info, subclasses must implement this method to consume discovery data 149s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 149s PASSED [ 50%] 149s tests/test_scanner.py::test_dbus_socket_missing_in_container 149s -------------------------------- live log setup -------------------------------- 149s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 149s -------------------------------- live log call --------------------------------- 149s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 149s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (1/4) 149s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 149s DEBUG habluetooth.scanner:scanner.py:462 hci0 (AA:BB:CC:DD:EE:FF): FileNotFoundError while starting bluetooth: 149s Traceback (most recent call last): 149s File "/usr/lib/python3/dist-packages/habluetooth/scanner.py", line 344, in _async_start_attempt 149s await self.scanner.start() 149s File "/usr/lib/python3.13/unittest/mock.py", line 2321, in _execute_mock_call 149s raise effect 149s FileNotFoundError 149s PASSED [ 51%] 149s tests/test_scanner.py::test_dbus_socket_missing 149s -------------------------------- live log setup -------------------------------- 149s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 149s -------------------------------- live log call --------------------------------- 149s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 149s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (1/4) 149s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 149s DEBUG habluetooth.scanner:scanner.py:462 hci0 (AA:BB:CC:DD:EE:FF): FileNotFoundError while starting bluetooth: 149s Traceback (most recent call last): 149s File "/usr/lib/python3/dist-packages/habluetooth/scanner.py", line 344, in _async_start_attempt 149s await self.scanner.start() 149s File "/usr/lib/python3.13/unittest/mock.py", line 2321, in _execute_mock_call 149s raise effect 149s FileNotFoundError 149s PASSED [ 52%] 149s tests/test_scanner.py::test_handle_cancellation 149s -------------------------------- live log setup -------------------------------- 149s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 149s -------------------------------- live log call --------------------------------- 149s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 149s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (1/4) 149s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 149s PASSED [ 53%] 149s tests/test_scanner.py::test_handle_stop_while_starting 149s -------------------------------- live log setup -------------------------------- 149s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 149s -------------------------------- live log call --------------------------------- 149s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 149s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (1/4) 149s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 149s DEBUG habluetooth.scanner:scanner.py:452 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth scanner aborted: 149s Traceback (most recent call last): 149s File "/usr/lib/python3/dist-packages/habluetooth/scanner.py", line 344, in _async_start_attempt 149s await self.scanner.start() 149s File "/tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/test_scanner.py", line 149, in _start 149s await asyncio.sleep(1000) 149s File "/usr/lib/python3.13/asyncio/tasks.py", line 718, in sleep 149s return await future 149s ^^^^^^^^^^^^ 149s asyncio.exceptions.CancelledError: Interrupted by interrupt context manager 149s 149s The above exception was the direct cause of the following exception: 149s 149s Traceback (most recent call last): 149s File "/usr/lib/python3/dist-packages/habluetooth/scanner.py", line 342, in _async_start_attempt 149s async_interrupt.interrupt(self._start_future, _AbortStartError, None), 149s ~~~~~~~~~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ 149s File "/usr/lib/python3/dist-packages/async_interrupt/__init__.py", line 90, in __aexit__ 149s raise self._exception from exc_val 149s habluetooth.scanner._AbortStartError 149s DEBUG habluetooth.scanner:scanner.py:571 hci0 (AA:BB:CC:DD:EE:FF): Scanner is already stopped 149s PASSED [ 54%] 149s tests/test_scanner.py::test_dbus_broken_pipe_in_container 149s -------------------------------- live log setup -------------------------------- 149s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 149s -------------------------------- live log call --------------------------------- 149s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 149s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (1/4) 149s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 149s DEBUG habluetooth.scanner:scanner.py:480 hci0 (AA:BB:CC:DD:EE:FF): DBus connection broken: 149s Traceback (most recent call last): 149s File "/usr/lib/python3/dist-packages/habluetooth/scanner.py", line 344, in _async_start_attempt 149s await self.scanner.start() 149s File "/usr/lib/python3.13/unittest/mock.py", line 2321, in _execute_mock_call 149s raise effect 149s BrokenPipeError 149s PASSED [ 55%] 149s tests/test_scanner.py::test_dbus_broken_pipe 149s -------------------------------- live log setup -------------------------------- 149s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 149s -------------------------------- live log call --------------------------------- 149s ERROR asyncio:base_events.py:1879 Future exception was never retrieved 149s future: 149s habluetooth.scanner._AbortStartError 149s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 149s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (1/4) 149s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 149s DEBUG habluetooth.scanner:scanner.py:480 hci0 (AA:BB:CC:DD:EE:FF): DBus connection broken: 149s Traceback (most recent call last): 149s File "/usr/lib/python3/dist-packages/habluetooth/scanner.py", line 344, in _async_start_attempt 149s await self.scanner.start() 149s File "/usr/lib/python3.13/unittest/mock.py", line 2321, in _execute_mock_call 149s raise effect 149s BrokenPipeError 149s PASSED [ 56%] 149s tests/test_scanner.py::test_invalid_dbus_message 149s -------------------------------- live log setup -------------------------------- 149s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 149s -------------------------------- live log call --------------------------------- 149s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 149s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (1/4) 149s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 149s DEBUG habluetooth.scanner:scanner.py:495 hci0 (AA:BB:CC:DD:EE:FF): Invalid DBus message received: 149s Traceback (most recent call last): 149s File "/usr/lib/python3/dist-packages/habluetooth/scanner.py", line 344, in _async_start_attempt 149s await self.scanner.start() 149s File "/usr/lib/python3.13/unittest/mock.py", line 2321, in _execute_mock_call 149s raise effect 149s dbus_fast.errors.InvalidMessageError 149s PASSED [ 57%] 149s tests/test_scanner.py::test_adapter_needs_reset_at_start[org.bluez.Error.Failed] 149s -------------------------------- live log setup -------------------------------- 149s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 149s -------------------------------- live log call --------------------------------- 149s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 149s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (1/4) 149s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 149s DEBUG habluetooth.scanner:scanner.py:434 hci0 (AA:BB:CC:DD:EE:FF): BleakError while starting bluetooth; attempt: (1/4): org.bluez.Error.Failed 149s Traceback (most recent call last): 149s File "/usr/lib/python3/dist-packages/habluetooth/scanner.py", line 344, in _async_start_attempt 149s await self.scanner.start() 149s File "/tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/test_scanner.py", line 249, in start 149s raise BleakError(error) 149s bleak.exc.BleakError: org.bluez.Error.Failed 149s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 149s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (2/4) 149s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 149s DEBUG habluetooth.scanner:scanner.py:555 hci0 (AA:BB:CC:DD:EE:FF): adapter stopped responding; executing reset 149s DEBUG habluetooth.scanner:scanner.py:557 hci0 (AA:BB:CC:DD:EE:FF): adapter reset result: True 149s DEBUG habluetooth.scanner:scanner.py:434 hci0 (AA:BB:CC:DD:EE:FF): BleakError while starting bluetooth; attempt: (2/4): org.bluez.Error.Failed 149s Traceback (most recent call last): 149s File "/usr/lib/python3/dist-packages/habluetooth/scanner.py", line 344, in _async_start_attempt 149s await self.scanner.start() 149s File "/tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/test_scanner.py", line 249, in start 149s raise BleakError(error) 149s bleak.exc.BleakError: org.bluez.Error.Failed 149s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 149s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (3/4) 149s DEBUG habluetooth.scanner:scanner.py:418 hci0 (AA:BB:CC:DD:EE:FF): Success while starting bluetooth; attempt: (3/4) 157s DEBUG bleak_retry_connector.bleak_manager:bleak_manager.py:56 Timed out trying to connect to DBus; will not try again until next restart 157s DEBUG bleak_retry_connector:__init__.py:639 Failed to restore discoveries for hci0 157s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 157s PASSED [ 58%] 157s tests/test_scanner.py::test_adapter_needs_reset_at_start[org.bluez.Error.InProgress] 157s -------------------------------- live log setup -------------------------------- 157s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 157s -------------------------------- live log call --------------------------------- 157s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 157s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (1/4) 157s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 157s DEBUG habluetooth.scanner:scanner.py:586 hci0 (AA:BB:CC:DD:EE:FF): Force stopping bluetooth discovery 157s ERROR bleak_retry_connector.bluez:bluez.py:324 Failed to stop discovery for hci0 because no manager 157s DEBUG habluetooth.scanner:scanner.py:434 hci0 (AA:BB:CC:DD:EE:FF): BleakError while starting bluetooth; attempt: (1/4): org.bluez.Error.InProgress 157s Traceback (most recent call last): 157s File "/usr/lib/python3/dist-packages/habluetooth/scanner.py", line 344, in _async_start_attempt 157s await self.scanner.start() 157s File "/tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/test_scanner.py", line 249, in start 157s raise BleakError(error) 157s bleak.exc.BleakError: org.bluez.Error.InProgress 157s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 157s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (2/4) 157s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 157s DEBUG habluetooth.scanner:scanner.py:586 hci0 (AA:BB:CC:DD:EE:FF): Force stopping bluetooth discovery 157s ERROR bleak_retry_connector.bluez:bluez.py:324 Failed to stop discovery for hci0 because no manager 157s DEBUG habluetooth.scanner:scanner.py:555 hci0 (AA:BB:CC:DD:EE:FF): adapter stopped responding; executing reset 157s DEBUG habluetooth.scanner:scanner.py:557 hci0 (AA:BB:CC:DD:EE:FF): adapter reset result: True 157s DEBUG habluetooth.scanner:scanner.py:434 hci0 (AA:BB:CC:DD:EE:FF): BleakError while starting bluetooth; attempt: (2/4): org.bluez.Error.InProgress 157s Traceback (most recent call last): 157s File "/usr/lib/python3/dist-packages/habluetooth/scanner.py", line 344, in _async_start_attempt 157s await self.scanner.start() 157s File "/tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/test_scanner.py", line 249, in start 157s raise BleakError(error) 157s bleak.exc.BleakError: org.bluez.Error.InProgress 157s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 157s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (3/4) 157s DEBUG habluetooth.scanner:scanner.py:418 hci0 (AA:BB:CC:DD:EE:FF): Success while starting bluetooth; attempt: (3/4) 157s DEBUG bleak_retry_connector:__init__.py:639 Failed to restore discoveries for hci0 157s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 157s PASSED [ 60%] 157s tests/test_scanner.py::test_adapter_needs_reset_at_start[org.bluez.Error.NotReady] 157s -------------------------------- live log setup -------------------------------- 157s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 157s -------------------------------- live log call --------------------------------- 157s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 157s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (1/4) 157s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 157s DEBUG habluetooth.scanner:scanner.py:434 hci0 (AA:BB:CC:DD:EE:FF): BleakError while starting bluetooth; attempt: (1/4): org.bluez.Error.NotReady 157s Traceback (most recent call last): 157s File "/usr/lib/python3/dist-packages/habluetooth/scanner.py", line 344, in _async_start_attempt 157s await self.scanner.start() 157s File "/tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/test_scanner.py", line 249, in start 157s raise BleakError(error) 157s bleak.exc.BleakError: org.bluez.Error.NotReady 157s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 157s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (2/4) 157s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 157s DEBUG habluetooth.scanner:scanner.py:555 hci0 (AA:BB:CC:DD:EE:FF): adapter stopped responding; executing reset 157s DEBUG habluetooth.scanner:scanner.py:557 hci0 (AA:BB:CC:DD:EE:FF): adapter reset result: True 157s DEBUG habluetooth.scanner:scanner.py:434 hci0 (AA:BB:CC:DD:EE:FF): BleakError while starting bluetooth; attempt: (2/4): org.bluez.Error.NotReady 157s Traceback (most recent call last): 157s File "/usr/lib/python3/dist-packages/habluetooth/scanner.py", line 344, in _async_start_attempt 157s await self.scanner.start() 157s File "/tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/test_scanner.py", line 249, in start 157s raise BleakError(error) 157s bleak.exc.BleakError: org.bluez.Error.NotReady 158s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 158s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (3/4) 158s DEBUG habluetooth.scanner:scanner.py:418 hci0 (AA:BB:CC:DD:EE:FF): Success while starting bluetooth; attempt: (3/4) 158s DEBUG bleak_retry_connector:__init__.py:639 Failed to restore discoveries for hci0 158s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 158s PASSED [ 61%] 158s tests/test_scanner.py::test_adapter_needs_reset_at_start[not found] 158s -------------------------------- live log setup -------------------------------- 158s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 158s -------------------------------- live log call --------------------------------- 158s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 158s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (1/4) 158s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 158s DEBUG habluetooth.scanner:scanner.py:434 hci0 (AA:BB:CC:DD:EE:FF): BleakError while starting bluetooth; attempt: (1/4): not found 158s Traceback (most recent call last): 158s File "/usr/lib/python3/dist-packages/habluetooth/scanner.py", line 344, in _async_start_attempt 158s await self.scanner.start() 158s File "/tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/test_scanner.py", line 249, in start 158s raise BleakError(error) 158s bleak.exc.BleakError: not found 158s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 158s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (2/4) 158s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 158s DEBUG habluetooth.scanner:scanner.py:555 hci0 (AA:BB:CC:DD:EE:FF): adapter stopped responding; executing reset 158s DEBUG habluetooth.scanner:scanner.py:557 hci0 (AA:BB:CC:DD:EE:FF): adapter reset result: True 158s DEBUG habluetooth.scanner:scanner.py:434 hci0 (AA:BB:CC:DD:EE:FF): BleakError while starting bluetooth; attempt: (2/4): not found 158s Traceback (most recent call last): 158s File "/usr/lib/python3/dist-packages/habluetooth/scanner.py", line 344, in _async_start_attempt 158s await self.scanner.start() 158s File "/tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/test_scanner.py", line 249, in start 158s raise BleakError(error) 158s bleak.exc.BleakError: not found 158s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 158s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (3/4) 158s DEBUG habluetooth.scanner:scanner.py:418 hci0 (AA:BB:CC:DD:EE:FF): Success while starting bluetooth; attempt: (3/4) 158s DEBUG bleak_retry_connector:__init__.py:639 Failed to restore discoveries for hci0 158s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 158s PASSED [ 62%] 158s tests/test_scanner.py::test_recovery_from_dbus_restart 158s -------------------------------- live log setup -------------------------------- 158s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 158s -------------------------------- live log call --------------------------------- 158s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 158s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (1/4) 158s DEBUG habluetooth.scanner:scanner.py:418 hci0 (AA:BB:CC:DD:EE:FF): Success while starting bluetooth; attempt: (1/4) 158s DEBUG bleak_retry_connector:__init__.py:639 Failed to restore discoveries for hci0 158s DEBUG habluetooth.base_scanner:base_scanner.py:210 hci0 (AA:BB:CC:DD:EE:FF): Scanner watchdog time_since_last_detection: 10.004502457000001 158s DEBUG habluetooth.base_scanner:base_scanner.py:210 hci0 (AA:BB:CC:DD:EE:FF): Scanner watchdog time_since_last_detection: 20.0 158s DEBUG habluetooth.base_scanner:base_scanner.py:210 hci0 (AA:BB:CC:DD:EE:FF): Scanner watchdog time_since_last_detection: 109.99999999999999 158s DEBUG habluetooth.scanner:scanner.py:517 hci0 (AA:BB:CC:DD:EE:FF): Bluetooth scanner has gone quiet for 109.99999999999999s, restarting 158s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 158s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 158s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (1/4) 158s DEBUG habluetooth.scanner:scanner.py:418 hci0 (AA:BB:CC:DD:EE:FF): Success while starting bluetooth; attempt: (1/4) 158s DEBUG bleak_retry_connector:__init__.py:639 Failed to restore discoveries for hci0 158s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 158s PASSED [ 63%] 158s tests/test_scanner.py::test_adapter_recovery 158s -------------------------------- live log setup -------------------------------- 158s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 158s -------------------------------- live log call --------------------------------- 158s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 158s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (1/4) 158s DEBUG habluetooth.scanner:scanner.py:418 hci0 (AA:BB:CC:DD:EE:FF): Success while starting bluetooth; attempt: (1/4) 158s DEBUG bleak_retry_connector:__init__.py:639 Failed to restore discoveries for hci0 158s DEBUG habluetooth.base_scanner:base_scanner.py:210 hci0 (AA:BB:CC:DD:EE:FF): Scanner watchdog time_since_last_detection: 10.0 158s DEBUG habluetooth.base_scanner:base_scanner.py:210 hci0 (AA:BB:CC:DD:EE:FF): Scanner watchdog time_since_last_detection: 20.0 158s DEBUG habluetooth.base_scanner:base_scanner.py:210 hci0 (AA:BB:CC:DD:EE:FF): Scanner watchdog time_since_last_detection: 120.00000000000001 158s DEBUG habluetooth.scanner:scanner.py:517 hci0 (AA:BB:CC:DD:EE:FF): Bluetooth scanner has gone quiet for 120.00000000000001s, restarting 158s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 158s DEBUG habluetooth.scanner:scanner.py:555 hci0 (AA:BB:CC:DD:EE:FF): adapter stopped responding; executing reset 158s DEBUG habluetooth.scanner:scanner.py:557 hci0 (AA:BB:CC:DD:EE:FF): adapter reset result: True 158s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 158s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (1/4) 158s DEBUG habluetooth.scanner:scanner.py:418 hci0 (AA:BB:CC:DD:EE:FF): Success while starting bluetooth; attempt: (1/4) 158s DEBUG bleak_retry_connector:__init__.py:639 Failed to restore discoveries for hci0 158s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 158s PASSED [ 64%] 158s tests/test_scanner.py::test_adapter_scanner_fails_to_start_first_time 158s -------------------------------- live log setup -------------------------------- 158s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 158s -------------------------------- live log call --------------------------------- 158s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 158s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (1/4) 158s DEBUG habluetooth.scanner:scanner.py:418 hci0 (AA:BB:CC:DD:EE:FF): Success while starting bluetooth; attempt: (1/4) 158s DEBUG bleak_retry_connector:__init__.py:639 Failed to restore discoveries for hci0 158s DEBUG habluetooth.base_scanner:base_scanner.py:210 hci0 (AA:BB:CC:DD:EE:FF): Scanner watchdog time_since_last_detection: 10.0 158s DEBUG habluetooth.base_scanner:base_scanner.py:210 hci0 (AA:BB:CC:DD:EE:FF): Scanner watchdog time_since_last_detection: 20.0 158s DEBUG habluetooth.base_scanner:base_scanner.py:210 hci0 (AA:BB:CC:DD:EE:FF): Scanner watchdog time_since_last_detection: 120.00000000000001 158s DEBUG habluetooth.scanner:scanner.py:517 hci0 (AA:BB:CC:DD:EE:FF): Bluetooth scanner has gone quiet for 120.00000000000001s, restarting 158s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 158s DEBUG habluetooth.scanner:scanner.py:555 hci0 (AA:BB:CC:DD:EE:FF): adapter stopped responding; executing reset 158s DEBUG habluetooth.scanner:scanner.py:557 hci0 (AA:BB:CC:DD:EE:FF): adapter reset result: True 158s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 158s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (1/4) 158s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 158s DEBUG habluetooth.scanner:scanner.py:434 hci0 (AA:BB:CC:DD:EE:FF): BleakError while starting bluetooth; attempt: (1/4): Failed to start 158s Traceback (most recent call last): 158s File "/usr/lib/python3/dist-packages/habluetooth/scanner.py", line 344, in _async_start_attempt 158s await self.scanner.start() 158s File "/tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/test_scanner.py", line 485, in start 158s raise BleakError("Failed to start") 158s bleak.exc.BleakError: Failed to start 158s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 158s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (2/4) 158s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 158s DEBUG habluetooth.scanner:scanner.py:434 hci0 (AA:BB:CC:DD:EE:FF): BleakError while starting bluetooth; attempt: (2/4): Failed to start 158s Traceback (most recent call last): 158s File "/usr/lib/python3/dist-packages/habluetooth/scanner.py", line 344, in _async_start_attempt 158s await self.scanner.start() 158s File "/tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/test_scanner.py", line 485, in start 158s raise BleakError("Failed to start") 158s bleak.exc.BleakError: Failed to start 158s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 158s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (3/4) 158s DEBUG habluetooth.scanner:scanner.py:418 hci0 (AA:BB:CC:DD:EE:FF): Success while starting bluetooth; attempt: (3/4) 158s DEBUG bleak_retry_connector:__init__.py:639 Failed to restore discoveries for hci0 158s DEBUG habluetooth.base_scanner:base_scanner.py:210 hci0 (AA:BB:CC:DD:EE:FF): Scanner watchdog time_since_last_detection: 90.00489190600001 158s DEBUG habluetooth.scanner:scanner.py:517 hci0 (AA:BB:CC:DD:EE:FF): Bluetooth scanner has gone quiet for 90.00489190600001s, restarting 158s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 158s DEBUG habluetooth.scanner:scanner.py:555 hci0 (AA:BB:CC:DD:EE:FF): adapter stopped responding; executing reset 158s DEBUG habluetooth.scanner:scanner.py:557 hci0 (AA:BB:CC:DD:EE:FF): adapter reset result: True 158s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 158s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (1/4) 158s DEBUG habluetooth.scanner:scanner.py:418 hci0 (AA:BB:CC:DD:EE:FF): Success while starting bluetooth; attempt: (1/4) 158s DEBUG bleak_retry_connector:__init__.py:639 Failed to restore discoveries for hci0 158s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 158s PASSED [ 65%] 158s tests/test_scanner.py::test_adapter_fails_to_start_and_takes_a_bit_to_init 158s -------------------------------- live log setup -------------------------------- 158s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 158s -------------------------------- live log call --------------------------------- 158s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 158s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (1/4) 158s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 158s DEBUG habluetooth.scanner:scanner.py:402 hci0 (AA:BB:CC:DD:EE:FF): Waiting for adapter to initialize; attempt (1/4) 158s DEBUG habluetooth.scanner:scanner.py:434 hci0 (AA:BB:CC:DD:EE:FF): BleakError while starting bluetooth; attempt: (1/4): org.freedesktop.DBus.Error.UnknownObject 158s Traceback (most recent call last): 158s File "/usr/lib/python3/dist-packages/habluetooth/scanner.py", line 344, in _async_start_attempt 158s await self.scanner.start() 158s File "/tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/test_scanner.py", line 599, in start 158s raise BleakError("org.freedesktop.DBus.Error.UnknownObject") 158s bleak.exc.BleakError: org.freedesktop.DBus.Error.UnknownObject 158s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 158s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (2/4) 158s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 158s DEBUG habluetooth.scanner:scanner.py:586 hci0 (AA:BB:CC:DD:EE:FF): Force stopping bluetooth discovery 158s ERROR bleak_retry_connector.bluez:bluez.py:324 Failed to stop discovery for hci0 because no manager 158s DEBUG habluetooth.scanner:scanner.py:555 hci0 (AA:BB:CC:DD:EE:FF): adapter stopped responding; executing reset 158s DEBUG habluetooth.scanner:scanner.py:557 hci0 (AA:BB:CC:DD:EE:FF): adapter reset result: True 158s DEBUG habluetooth.scanner:scanner.py:434 hci0 (AA:BB:CC:DD:EE:FF): BleakError while starting bluetooth; attempt: (2/4): org.bluez.Error.InProgress 158s Traceback (most recent call last): 158s File "/usr/lib/python3/dist-packages/habluetooth/scanner.py", line 344, in _async_start_attempt 158s await self.scanner.start() 158s File "/tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/test_scanner.py", line 601, in start 158s raise BleakError("org.bluez.Error.InProgress") 158s bleak.exc.BleakError: org.bluez.Error.InProgress 158s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 158s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (3/4) 158s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 158s DEBUG habluetooth.scanner:scanner.py:586 hci0 (AA:BB:CC:DD:EE:FF): Force stopping bluetooth discovery 158s ERROR bleak_retry_connector.bluez:bluez.py:324 Failed to stop discovery for hci0 because no manager 158s DEBUG habluetooth.scanner:scanner.py:434 hci0 (AA:BB:CC:DD:EE:FF): BleakError while starting bluetooth; attempt: (3/4): org.bluez.Error.InProgress 158s Traceback (most recent call last): 158s File "/usr/lib/python3/dist-packages/habluetooth/scanner.py", line 344, in _async_start_attempt 158s await self.scanner.start() 158s File "/tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/test_scanner.py", line 603, in start 158s raise BleakError("org.bluez.Error.InProgress") 158s bleak.exc.BleakError: org.bluez.Error.InProgress 158s DEBUG habluetooth.scanner:scanner.py:324 hci0 (AA:BB:CC:DD:EE:FF): Falling back to passive scanning mode after active scanning failed (4/4) 158s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'passive', 'adapter': 'hci0', 'bluez': } 158s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (4/4) 158s WARNING habluetooth.scanner:scanner.py:411 hci0 (AA:BB:CC:DD:EE:FF): Successful fall-back to passive scanning mode after active scanning failed (4/4) 158s DEBUG habluetooth.scanner:scanner.py:418 hci0 (AA:BB:CC:DD:EE:FF): Success while starting bluetooth; attempt: (4/4) 158s DEBUG bleak_retry_connector:__init__.py:639 Failed to restore discoveries for hci0 158s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 158s PASSED [ 66%] 158s tests/test_scanner.py::test_restart_takes_longer_than_watchdog_time 158s -------------------------------- live log setup -------------------------------- 158s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 158s -------------------------------- live log call --------------------------------- 158s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 158s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (1/4) 158s DEBUG habluetooth.scanner:scanner.py:418 hci0 (AA:BB:CC:DD:EE:FF): Success while starting bluetooth; attempt: (1/4) 158s DEBUG bleak_retry_connector:__init__.py:639 Failed to restore discoveries for hci0 158s DEBUG habluetooth.base_scanner:base_scanner.py:210 hci0 (AA:BB:CC:DD:EE:FF): Scanner watchdog time_since_last_detection: 120.00000000000001 158s DEBUG habluetooth.scanner:scanner.py:517 hci0 (AA:BB:CC:DD:EE:FF): Bluetooth scanner has gone quiet for 120.00000000000001s, restarting 158s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 158s DEBUG habluetooth.scanner:scanner.py:555 hci0 (AA:BB:CC:DD:EE:FF): adapter stopped responding; executing reset 158s DEBUG habluetooth.scanner:scanner.py:557 hci0 (AA:BB:CC:DD:EE:FF): adapter reset result: True 158s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 158s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (1/4) 158s DEBUG habluetooth.base_scanner:base_scanner.py:210 hci0 (AA:BB:CC:DD:EE:FF): Scanner watchdog time_since_last_detection: 120.00000000000001 158s DEBUG habluetooth.scanner:scanner.py:512 hci0 (AA:BB:CC:DD:EE:FF): Scanner is already restarting, deferring restart 158s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 158s DEBUG habluetooth.scanner:scanner.py:426 hci0 (AA:BB:CC:DD:EE:FF): TimeoutError while starting bluetooth; attempt: (1/4) 158s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 158s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (2/4) 158s DEBUG habluetooth.scanner:scanner.py:418 hci0 (AA:BB:CC:DD:EE:FF): Success while starting bluetooth; attempt: (2/4) 158s DEBUG bleak_retry_connector:__init__.py:639 Failed to restore discoveries for hci0 158s ERROR asyncio:base_events.py:1879 Future exception was never retrieved 158s future: 158s habluetooth.scanner._AbortStartError 158s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 158s PASSED [ 67%] 158s tests/test_scanner.py::test_setup_and_stop_macos SKIPPED (condition:...) [ 68%] 158s tests/test_scanner.py::test_adapter_init_fails_fallback_to_passive 158s -------------------------------- live log setup -------------------------------- 158s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 158s -------------------------------- live log call --------------------------------- 158s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 158s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (1/4) 158s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 158s DEBUG habluetooth.scanner:scanner.py:402 hci0 (AA:BB:CC:DD:EE:FF): Waiting for adapter to initialize; attempt (1/4) 158s DEBUG habluetooth.scanner:scanner.py:434 hci0 (AA:BB:CC:DD:EE:FF): BleakError while starting bluetooth; attempt: (1/4): org.freedesktop.DBus.Error.UnknownObject 158s Traceback (most recent call last): 158s File "/usr/lib/python3/dist-packages/habluetooth/scanner.py", line 344, in _async_start_attempt 158s await self.scanner.start() 158s File "/tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/test_scanner.py", line 780, in start 158s raise BleakError("org.freedesktop.DBus.Error.UnknownObject") 158s bleak.exc.BleakError: org.freedesktop.DBus.Error.UnknownObject 158s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 158s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (2/4) 158s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 158s DEBUG habluetooth.scanner:scanner.py:586 hci0 (AA:BB:CC:DD:EE:FF): Force stopping bluetooth discovery 158s ERROR bleak_retry_connector.bluez:bluez.py:324 Failed to stop discovery for hci0 because no manager 158s DEBUG habluetooth.scanner:scanner.py:555 hci0 (AA:BB:CC:DD:EE:FF): adapter stopped responding; executing reset 158s DEBUG habluetooth.scanner:scanner.py:557 hci0 (AA:BB:CC:DD:EE:FF): adapter reset result: True 158s DEBUG habluetooth.scanner:scanner.py:434 hci0 (AA:BB:CC:DD:EE:FF): BleakError while starting bluetooth; attempt: (2/4): org.bluez.Error.InProgress 158s Traceback (most recent call last): 158s File "/usr/lib/python3/dist-packages/habluetooth/scanner.py", line 344, in _async_start_attempt 158s await self.scanner.start() 158s File "/tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/test_scanner.py", line 782, in start 158s raise BleakError("org.bluez.Error.InProgress") 158s bleak.exc.BleakError: org.bluez.Error.InProgress 158s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'active', 'adapter': 'hci0'} 158s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (3/4) 158s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 158s DEBUG habluetooth.scanner:scanner.py:586 hci0 (AA:BB:CC:DD:EE:FF): Force stopping bluetooth discovery 158s ERROR bleak_retry_connector.bluez:bluez.py:324 Failed to stop discovery for hci0 because no manager 158s DEBUG habluetooth.scanner:scanner.py:434 hci0 (AA:BB:CC:DD:EE:FF): BleakError while starting bluetooth; attempt: (3/4): org.bluez.Error.InProgress 158s Traceback (most recent call last): 158s File "/usr/lib/python3/dist-packages/habluetooth/scanner.py", line 344, in _async_start_attempt 158s await self.scanner.start() 158s File "/tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/test_scanner.py", line 784, in start 158s raise BleakError("org.bluez.Error.InProgress") 158s bleak.exc.BleakError: org.bluez.Error.InProgress 158s DEBUG habluetooth.scanner:scanner.py:324 hci0 (AA:BB:CC:DD:EE:FF): Falling back to passive scanning mode after active scanning failed (4/4) 158s DEBUG habluetooth.scanner:scanner.py:142 Initializing bluetooth scanner with {'detection_callback': >, 'scanning_mode': 'passive', 'adapter': 'hci0', 'bluez': } 158s DEBUG habluetooth.scanner:scanner.py:444 hci0 (AA:BB:CC:DD:EE:FF): Starting bluetooth discovery attempt: (4/4) 158s WARNING habluetooth.scanner:scanner.py:411 hci0 (AA:BB:CC:DD:EE:FF): Successful fall-back to passive scanning mode after active scanning failed (4/4) 158s DEBUG habluetooth.scanner:scanner.py:418 hci0 (AA:BB:CC:DD:EE:FF): Success while starting bluetooth; attempt: (4/4) 158s DEBUG bleak_retry_connector:__init__.py:639 Failed to restore discoveries for hci0 158s DEBUG habluetooth.scanner:scanner.py:573 hci0 (AA:BB:CC:DD:EE:FF): Stopping bluetooth discovery 158s PASSED [ 70%] 158s tests/test_storage.py::test_discovered_device_advertisement_data_to_dict PASSED [ 71%] 158s tests/test_storage.py::test_discovered_device_advertisement_data_from_dict PASSED [ 72%] 158s tests/test_storage.py::test_expire_stale_scanner_discovered_device_advertisement_data 158s -------------------------------- live log call --------------------------------- 158s DEBUG habluetooth.storage:storage.py:122 Loaded 1 fresh discovered devices for myscanner 158s DEBUG habluetooth.storage:storage.py:122 Loaded 0 fresh discovered devices for all_expired 158s PASSED [ 73%] 158s tests/test_storage.py::test_expire_future_discovered_device_advertisement_data 158s -------------------------------- live log call --------------------------------- 158s DEBUG habluetooth.storage:storage.py:122 Loaded 1 fresh discovered devices for myscanner 158s WARNING habluetooth.storage:storage.py:107 Discarding timestamp 1765990558.3571713 for CC:DD:EE:FF:AA:BB on scanner all_future as it is the future (now = 1764990558.3571782) 158s DEBUG habluetooth.storage:storage.py:122 Loaded 0 fresh discovered devices for all_future 158s PASSED [ 74%] 158s tests/test_storage.py::test_discovered_device_advertisement_data_from_dict_corrupt 158s -------------------------------- live log call --------------------------------- 158s ERROR habluetooth.storage:storage.py:147 Error deserializing discovered_device_advertisement_data, adapter startup will be slow: BLEDevice.__init__() missing 1 required positional argument: 'name' 158s Traceback (most recent call last): 158s File "/usr/lib/python3/dist-packages/habluetooth/storage.py", line 138, in discovered_device_advertisement_data_from_dict 158s _deserialize_discovered_device_advertisement_datas( 158s ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~^ 158s data[DISCOVERED_DEVICE_ADVERTISEMENT_DATAS] 158s ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ 158s ), 158s ^ 158s File "/usr/lib/python3/dist-packages/habluetooth/storage.py", line 198, in _deserialize_discovered_device_advertisement_datas 158s _ble_device_from_dict(device_advertisement_data["device"]), 158s ~~~~~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ 158s File "/usr/lib/python3/dist-packages/habluetooth/storage.py", line 215, in _ble_device_from_dict 158s return BLEDevice(**device_data) 158s TypeError: BLEDevice.__init__() missing 1 required positional argument: 'name' 158s PASSED [ 75%] 158s tests/test_storage.py::test_backward_compatibility_rssi_in_device_dict PASSED [ 76%] 158s tests/test_wrappers.py::test_test_switch_adapters_when_out_of_slots 158s -------------------------------- live log setup -------------------------------- 158s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 158s -------------------------------- live log call --------------------------------- 158s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (00:00:00:00:00:01) 158s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci1 (00:00:00:00:00:02) 158s DEBUG habluetooth.wrappers:wrappers.py:279 00:00:00:00:00:01: Looking for backend to connect 158s INFO habluetooth.wrappers:wrappers.py:383 00:00:00:00:00:01 - any: Found 2 connection path(s), preferred order: hci0 (00:00:00:00:00:01) (RSSI=-60) (failures=0) (in_progress=0) (score=-60), hci1 (00:00:00:00:00:02) (RSSI=-80) (failures=0) (in_progress=0) (score=-80) 158s DEBUG habluetooth.wrappers:wrappers.py:305 00:00:00:00:00:01 - any -> /org/bluez/hci0: Connecting via hci0 (00:00:00:00:00:01) (last rssi: -60) 158s DEBUG habluetooth.wrappers:wrappers.py:326 00:00:00:00:00:01 - any -> /org/bluez/hci0: Connected via hci0 (00:00:00:00:00:01) (last rssi: -60) 158s DEBUG habluetooth.wrappers:wrappers.py:279 00:00:00:00:00:02: Looking for backend to connect 158s INFO habluetooth.wrappers:wrappers.py:383 00:00:00:00:00:02 - any: Found 2 connection path(s), preferred order: hci0 (00:00:00:00:00:01) (RSSI=-60) (failures=0) (in_progress=0) (score=-60), hci1 (00:00:00:00:00:02) (RSSI=-80) (failures=0) (in_progress=0) (score=-80) 158s DEBUG habluetooth.wrappers:wrappers.py:279 00:00:00:00:00:03: Looking for backend to connect 158s INFO habluetooth.wrappers:wrappers.py:383 00:00:00:00:00:03 - any: Found 2 connection path(s), preferred order: hci0 (00:00:00:00:00:01) (RSSI=-60) (failures=0) (in_progress=0) (score=-60), hci1 (00:00:00:00:00:02) (RSSI=-80) (failures=0) (in_progress=0) (score=-80) 158s DEBUG habluetooth.wrappers:wrappers.py:305 00:00:00:00:00:03 - any -> /org/bluez/hci1: Connecting via hci1 (00:00:00:00:00:02) (last rssi: -80) 158s DEBUG habluetooth.wrappers:wrappers.py:326 00:00:00:00:00:03 - any -> /org/bluez/hci1: Connected via hci1 (00:00:00:00:00:02) (last rssi: -80) 158s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (00:00:00:00:00:01) 158s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci1 (00:00:00:00:00:02) 158s PASSED [ 77%] 158s tests/test_wrappers.py::test_release_slot_on_connect_failure 158s -------------------------------- live log setup -------------------------------- 158s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 158s -------------------------------- live log call --------------------------------- 158s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (00:00:00:00:00:01) 158s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci1 (00:00:00:00:00:02) 158s DEBUG habluetooth.wrappers:wrappers.py:279 00:00:00:00:00:01: Looking for backend to connect 158s INFO habluetooth.wrappers:wrappers.py:383 00:00:00:00:00:01 - any: Found 2 connection path(s), preferred order: hci0 (00:00:00:00:00:01) (RSSI=-60) (failures=0) (in_progress=0) (score=-60), hci1 (00:00:00:00:00:02) (RSSI=-80) (failures=0) (in_progress=0) (score=-80) 158s DEBUG habluetooth.wrappers:wrappers.py:305 00:00:00:00:00:01 - any -> /org/bluez/hci0: Connecting via hci0 (00:00:00:00:00:01) (last rssi: -60) 158s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (00:00:00:00:00:01) 158s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci1 (00:00:00:00:00:02) 158s PASSED [ 78%] 158s tests/test_wrappers.py::test_release_slot_on_connect_exception 158s -------------------------------- live log setup -------------------------------- 158s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 158s -------------------------------- live log call --------------------------------- 158s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (00:00:00:00:00:01) 158s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci1 (00:00:00:00:00:02) 158s DEBUG habluetooth.wrappers:wrappers.py:279 00:00:00:00:00:01: Looking for backend to connect 158s INFO habluetooth.wrappers:wrappers.py:383 00:00:00:00:00:01 - any: Found 2 connection path(s), preferred order: hci0 (00:00:00:00:00:01) (RSSI=-60) (failures=0) (in_progress=0) (score=-60), hci1 (00:00:00:00:00:02) (RSSI=-80) (failures=0) (in_progress=0) (score=-80) 158s DEBUG habluetooth.wrappers:wrappers.py:305 00:00:00:00:00:01 - any -> /org/bluez/hci0: Connecting via hci0 (00:00:00:00:00:01) (last rssi: -60) 158s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (00:00:00:00:00:01) 158s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci1 (00:00:00:00:00:02) 158s PASSED [ 80%] 158s tests/test_wrappers.py::test_switch_adapters_on_failure 158s -------------------------------- live log setup -------------------------------- 158s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 158s -------------------------------- live log call --------------------------------- 158s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (00:00:00:00:00:01) 158s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci1 (00:00:00:00:00:02) 158s DEBUG habluetooth.wrappers:wrappers.py:279 00:00:00:00:00:01: Looking for backend to connect 158s INFO habluetooth.wrappers:wrappers.py:383 00:00:00:00:00:01 - any: Found 2 connection path(s), preferred order: hci0 (00:00:00:00:00:01) (RSSI=-60) (failures=0) (in_progress=0) (score=-60), hci1 (00:00:00:00:00:02) (RSSI=-80) (failures=0) (in_progress=0) (score=-80) 158s DEBUG habluetooth.wrappers:wrappers.py:305 00:00:00:00:00:01 - any -> /org/bluez/hci0: Connecting via hci0 (00:00:00:00:00:01) (last rssi: -60) 158s DEBUG habluetooth.wrappers:wrappers.py:279 00:00:00:00:00:01: Looking for backend to connect 158s INFO habluetooth.wrappers:wrappers.py:383 00:00:00:00:00:01 - any: Found 2 connection path(s), preferred order: hci0 (00:00:00:00:00:01) (RSSI=-60) (failures=1) (in_progress=0) (score=-60.0), hci1 (00:00:00:00:00:02) (RSSI=-80) (failures=0) (in_progress=0) (score=-80) 158s DEBUG habluetooth.wrappers:wrappers.py:305 00:00:00:00:00:01 - any -> /org/bluez/hci0: Connecting via hci0 (00:00:00:00:00:01) (last rssi: -60) 158s DEBUG habluetooth.wrappers:wrappers.py:279 00:00:00:00:00:01: Looking for backend to connect 158s INFO habluetooth.wrappers:wrappers.py:383 00:00:00:00:00:01 - any: Found 2 connection path(s), preferred order: hci1 (00:00:00:00:00:02) (RSSI=-80) (failures=0) (in_progress=0) (score=-80), hci0 (00:00:00:00:00:01) (RSSI=-60) (failures=2) (in_progress=0) (score=-60.0) 158s DEBUG habluetooth.wrappers:wrappers.py:305 00:00:00:00:00:01 - any -> /org/bluez/hci1: Connecting via hci1 (00:00:00:00:00:02) (last rssi: -80) 158s DEBUG habluetooth.wrappers:wrappers.py:326 00:00:00:00:00:01 - any -> /org/bluez/hci1: Connected via hci1 (00:00:00:00:00:02) (last rssi: -80) 158s DEBUG habluetooth.wrappers:wrappers.py:279 00:00:00:00:00:01: Looking for backend to connect 158s INFO habluetooth.wrappers:wrappers.py:383 00:00:00:00:00:01 - any: Found 2 connection path(s), preferred order: hci1 (00:00:00:00:00:02) (RSSI=-80) (failures=0) (in_progress=0) (score=-80), hci0 (00:00:00:00:00:01) (RSSI=-60) (failures=2) (in_progress=0) (score=-60.0) 158s DEBUG habluetooth.wrappers:wrappers.py:305 00:00:00:00:00:01 - any -> /org/bluez/hci1: Connecting via hci1 (00:00:00:00:00:02) (last rssi: -80) 158s DEBUG habluetooth.wrappers:wrappers.py:326 00:00:00:00:00:01 - any -> /org/bluez/hci1: Connected via hci1 (00:00:00:00:00:02) (last rssi: -80) 158s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (00:00:00:00:00:01) 158s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci1 (00:00:00:00:00:02) 158s PASSED [ 81%] 158s tests/test_wrappers.py::test_switch_adapters_on_connecting 158s -------------------------------- live log setup -------------------------------- 158s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 158s -------------------------------- live log call --------------------------------- 158s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (00:00:00:00:00:01) 158s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci1 (00:00:00:00:00:02) 158s DEBUG habluetooth.wrappers:wrappers.py:279 00:00:00:00:00:01: Looking for backend to connect 158s INFO habluetooth.wrappers:wrappers.py:383 00:00:00:00:00:01 - any: Found 2 connection path(s), preferred order: hci0 (00:00:00:00:00:01) (RSSI=-60) (failures=0) (in_progress=0) (score=-60), hci1 (00:00:00:00:00:02) (RSSI=-80) (failures=0) (in_progress=0) (score=-80) 158s DEBUG habluetooth.wrappers:wrappers.py:305 00:00:00:00:00:01 - any -> /org/bluez/hci0: Connecting via hci0 (00:00:00:00:00:01) (last rssi: -60) 158s DEBUG habluetooth.wrappers:wrappers.py:279 00:00:00:00:00:01: Looking for backend to connect 158s INFO habluetooth.wrappers:wrappers.py:383 00:00:00:00:00:01 - any: Found 2 connection path(s), preferred order: hci1 (00:00:00:00:00:02) (RSSI=-80) (failures=0) (in_progress=0) (score=-80), hci0 (00:00:00:00:00:01) (RSSI=-60) (failures=0) (in_progress=1) (score=-60.0) 158s DEBUG habluetooth.wrappers:wrappers.py:305 00:00:00:00:00:01 - any -> /org/bluez/hci1: Connecting via hci1 (00:00:00:00:00:02) (last rssi: -80) 158s DEBUG habluetooth.wrappers:wrappers.py:326 00:00:00:00:00:01 - any -> /org/bluez/hci1: Connected via hci1 (00:00:00:00:00:02) (last rssi: -80) 158s DEBUG habluetooth.wrappers:wrappers.py:326 00:00:00:00:00:01 - any -> /org/bluez/hci0: Connected via hci0 (00:00:00:00:00:01) (last rssi: -60) 158s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (00:00:00:00:00:01) 158s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci1 (00:00:00:00:00:02) 158s PASSED [ 82%] 158s tests/test_wrappers.py::test_single_adapter_connection_history 158s -------------------------------- live log setup -------------------------------- 158s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 158s -------------------------------- live log call --------------------------------- 158s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (AA:BB:CC:DD:EE:00) 158s DEBUG habluetooth.wrappers:wrappers.py:279 00:00:00:00:00:11: Looking for backend to connect 158s INFO habluetooth.wrappers:wrappers.py:383 00:00:00:00:00:11 - any: Found 1 connection path(s), preferred order: hci0 (AA:BB:CC:DD:EE:00) (RSSI=-60) (failures=0) (in_progress=0) (score=-60) 158s DEBUG habluetooth.wrappers:wrappers.py:305 00:00:00:00:00:11 - any -> /org/bluez/hci0: Connecting via hci0 (AA:BB:CC:DD:EE:00) (last rssi: -60) 158s DEBUG habluetooth.wrappers:wrappers.py:326 00:00:00:00:00:11 - any -> /org/bluez/hci0: Connected via hci0 (AA:BB:CC:DD:EE:00) (last rssi: -60) 158s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (AA:BB:CC:DD:EE:00) 158s PASSED [ 83%] 158s tests/test_wrappers.py::test_passing_subclassed_str_as_address 158s -------------------------------- live log setup -------------------------------- 158s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 158s -------------------------------- live log call --------------------------------- 158s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (00:00:00:00:00:01) 158s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci1 (00:00:00:00:00:02) 158s DEBUG habluetooth.wrappers:wrappers.py:279 00:00:00:00:00:01: Looking for backend to connect 158s INFO habluetooth.wrappers:wrappers.py:383 00:00:00:00:00:01 - any: Found 2 connection path(s), preferred order: hci0 (00:00:00:00:00:01) (RSSI=-60) (failures=0) (in_progress=0) (score=-60), hci1 (00:00:00:00:00:02) (RSSI=-80) (failures=0) (in_progress=0) (score=-80) 158s DEBUG habluetooth.wrappers:wrappers.py:305 00:00:00:00:00:01 - any -> /org/bluez/hci0: Connecting via hci0 (00:00:00:00:00:01) (last rssi: -60) 158s DEBUG habluetooth.wrappers:wrappers.py:326 00:00:00:00:00:01 - any -> /org/bluez/hci0: Connected via hci0 (00:00:00:00:00:01) (last rssi: -60) 158s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (00:00:00:00:00:01) 158s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci1 (00:00:00:00:00:02) 158s PASSED [ 84%] 158s tests/test_wrappers.py::test_find_device_by_address 158s -------------------------------- live log setup -------------------------------- 158s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 158s -------------------------------- live log call --------------------------------- 158s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (00:00:00:00:00:01) 158s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci1 (00:00:00:00:00:02) 158s PASSED [ 85%] 158s tests/test_wrappers.py::test_discover 158s -------------------------------- live log setup -------------------------------- 158s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 158s -------------------------------- live log call --------------------------------- 158s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (00:00:00:00:00:01) 158s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci1 (00:00:00:00:00:02) 158s PASSED [ 86%] 158s tests/test_wrappers.py::test_raise_after_shutdown 158s -------------------------------- live log setup -------------------------------- 158s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 158s -------------------------------- live log call --------------------------------- 158s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (00:00:00:00:00:01) 158s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci1 (00:00:00:00:00:02) 158s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (00:00:00:00:00:01) 158s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci1 (00:00:00:00:00:02) 158s PASSED [ 87%] 158s tests/test_wrappers.py::test_wrapped_instance_with_filter 158s -------------------------------- live log setup -------------------------------- 158s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 158s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (AA:BB:CC:DD:EE:00) 158s PASSED [ 88%] 158s ------------------------------ live log teardown ------------------------------- 158s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (AA:BB:CC:DD:EE:00) 158s 158s tests/test_wrappers.py::test_wrapped_instance_with_service_uuids 158s -------------------------------- live log setup -------------------------------- 158s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 158s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (AA:BB:CC:DD:EE:00) 158s PASSED [ 90%] 158s ------------------------------ live log teardown ------------------------------- 158s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (AA:BB:CC:DD:EE:00) 158s 158s tests/test_wrappers.py::test_wrapped_instance_with_service_uuids_with_coro_callback 158s -------------------------------- live log setup -------------------------------- 158s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 158s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (AA:BB:CC:DD:EE:00) 158s PASSED [ 91%] 158s ------------------------------ live log teardown ------------------------------- 158s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (AA:BB:CC:DD:EE:00) 158s 158s tests/test_wrappers.py::test_wrapped_instance_with_broken_callbacks 158s -------------------------------- live log setup -------------------------------- 158s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 158s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (AA:BB:CC:DD:EE:00) 158s PASSED [ 92%] 158s ------------------------------ live log teardown ------------------------------- 158s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (AA:BB:CC:DD:EE:00) 158s 158s tests/test_wrappers.py::test_wrapped_instance_changes_uuids 158s -------------------------------- live log setup -------------------------------- 158s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 158s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (AA:BB:CC:DD:EE:00) 158s PASSED [ 93%] 158s ------------------------------ live log teardown ------------------------------- 158s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (AA:BB:CC:DD:EE:00) 158s 158s tests/test_wrappers.py::test_wrapped_instance_changes_filters 158s -------------------------------- live log setup -------------------------------- 158s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 158s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (AA:BB:CC:DD:EE:00) 158s PASSED [ 94%] 158s ------------------------------ live log teardown ------------------------------- 158s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (AA:BB:CC:DD:EE:00) 158s 158s tests/test_wrappers.py::test_wrapped_instance_unsupported_filter 158s -------------------------------- live log setup -------------------------------- 158s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 158s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (AA:BB:CC:DD:EE:00) 158s -------------------------------- live log call --------------------------------- 158s WARNING habluetooth.wrappers:wrappers.py:120 Only UUIDs filters are supported 158s PASSED [ 95%] 158s ------------------------------ live log teardown ------------------------------- 158s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (AA:BB:CC:DD:EE:00) 158s 158s tests/test_wrappers.py::test_client_with_services_parameter 158s -------------------------------- live log setup -------------------------------- 158s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 158s -------------------------------- live log call --------------------------------- 158s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (00:00:00:00:00:01) 158s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci1 (00:00:00:00:00:02) 158s DEBUG habluetooth.wrappers:wrappers.py:279 00:00:00:00:00:01: Looking for backend to connect 158s INFO habluetooth.wrappers:wrappers.py:383 00:00:00:00:00:01 - any: Found 2 connection path(s), preferred order: hci0 (00:00:00:00:00:01) (RSSI=-60) (failures=0) (in_progress=0) (score=-60), hci1 (00:00:00:00:00:02) (RSSI=-80) (failures=0) (in_progress=0) (score=-80) 158s DEBUG habluetooth.wrappers:wrappers.py:305 00:00:00:00:00:01 - any -> /org/bluez/hci0: Connecting via hci0 (00:00:00:00:00:01) (last rssi: -60) 158s DEBUG habluetooth.wrappers:wrappers.py:326 00:00:00:00:00:01 - any -> /org/bluez/hci0: Connected via hci0 (00:00:00:00:00:01) (last rssi: -60) 158s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (00:00:00:00:00:01) 158s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci1 (00:00:00:00:00:02) 158s PASSED [ 96%] 158s tests/test_wrappers.py::test_client_with_pair_parameter 158s -------------------------------- live log setup -------------------------------- 158s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 158s -------------------------------- live log call --------------------------------- 158s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (00:00:00:00:00:01) 158s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci1 (00:00:00:00:00:02) 158s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (00:00:00:00:00:01) 158s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci1 (00:00:00:00:00:02) 158s PASSED [ 97%] 158s tests/test_wrappers.py::test_client_services_normalization 158s -------------------------------- live log setup -------------------------------- 158s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 158s -------------------------------- live log call --------------------------------- 158s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (00:00:00:00:00:01) 158s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci1 (00:00:00:00:00:02) 158s DEBUG habluetooth.wrappers:wrappers.py:279 00:00:00:00:00:01: Looking for backend to connect 158s INFO habluetooth.wrappers:wrappers.py:383 00:00:00:00:00:01 - any: Found 2 connection path(s), preferred order: hci0 (00:00:00:00:00:01) (RSSI=-60) (failures=0) (in_progress=0) (score=-60), hci1 (00:00:00:00:00:02) (RSSI=-80) (failures=0) (in_progress=0) (score=-80) 158s DEBUG habluetooth.wrappers:wrappers.py:305 00:00:00:00:00:01 - any -> /org/bluez/hci0: Connecting via hci0 (00:00:00:00:00:01) (last rssi: -60) 158s DEBUG habluetooth.wrappers:wrappers.py:326 00:00:00:00:00:01 - any -> /org/bluez/hci0: Connected via hci0 (00:00:00:00:00:01) (last rssi: -60) 158s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (00:00:00:00:00:01) 158s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci1 (00:00:00:00:00:02) 158s PASSED [ 98%] 158s tests/test_wrappers.py::test_client_with_none_services 158s -------------------------------- live log setup -------------------------------- 158s DEBUG asyncio:selector_events.py:64 Using selector: EpollSelector 158s -------------------------------- live log call --------------------------------- 158s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci0 (00:00:00:00:00:01) 158s DEBUG habluetooth.manager:manager.py:765 Registering scanner hci1 (00:00:00:00:00:02) 158s DEBUG habluetooth.wrappers:wrappers.py:279 00:00:00:00:00:01: Looking for backend to connect 158s INFO habluetooth.wrappers:wrappers.py:383 00:00:00:00:00:01 - any: Found 2 connection path(s), preferred order: hci0 (00:00:00:00:00:01) (RSSI=-60) (failures=0) (in_progress=0) (score=-60), hci1 (00:00:00:00:00:02) (RSSI=-80) (failures=0) (in_progress=0) (score=-80) 158s DEBUG habluetooth.wrappers:wrappers.py:305 00:00:00:00:00:01 - any -> /org/bluez/hci0: Connecting via hci0 (00:00:00:00:00:01) (last rssi: -60) 158s DEBUG habluetooth.wrappers:wrappers.py:326 00:00:00:00:00:01 - any -> /org/bluez/hci0: Connected via hci0 (00:00:00:00:00:01) (last rssi: -60) 158s DEBUG habluetooth.wrappers:wrappers.py:279 00:00:00:00:00:01: Looking for backend to connect 158s INFO habluetooth.wrappers:wrappers.py:383 00:00:00:00:00:01 - any: Found 2 connection path(s), preferred order: hci0 (00:00:00:00:00:01) (RSSI=-60) (failures=0) (in_progress=0) (score=-60), hci1 (00:00:00:00:00:02) (RSSI=-80) (failures=0) (in_progress=0) (score=-80) 158s DEBUG habluetooth.wrappers:wrappers.py:305 00:00:00:00:00:01 - any -> /org/bluez/hci0: Connecting via hci0 (00:00:00:00:00:01) (last rssi: -60) 158s DEBUG habluetooth.wrappers:wrappers.py:326 00:00:00:00:00:01 - any -> /org/bluez/hci0: Connected via hci0 (00:00:00:00:00:01) (last rssi: -60) 158s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci0 (00:00:00:00:00:01) 158s DEBUG habluetooth.manager:manager.py:748 Unregistering scanner hci1 (00:00:00:00:00:02) 158s PASSED [100%] 158s ------------------------------ live log teardown ------------------------------- 158s DEBUG habluetooth.manager:manager.py:322 Stopping bluetooth manager 158s 158s 158s =============================== warnings summary =============================== 158s tests/test_base_scanner.py: 9 warnings 158s tests/test_manager.py: 3 warnings 158s tests/test_wrappers.py: 14 warnings 158s /tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/__init__.py:64: DeprecationWarning: Passing additional arguments for BLEDevice is deprecated and has no effect. 158s return BLEDevice(**new) 158s 158s tests/test_base_scanner.py::test_remote_scanner_expires_non_connectable 158s /tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/test_base_scanner.py:326: FutureWarning: BaseHaRemoteScanner._discovered_device_timestamps is deprecated and will be removed in a future version of habluetooth, use BaseHaRemoteScanner.discovered_device_timestamps instead 158s assert len(scanner._discovered_device_timestamps) == 1 158s 158s tests/test_base_scanner.py::test_remote_scanner_expires_non_connectable 158s /tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/test_base_scanner.py:358: FutureWarning: BaseHaRemoteScanner._discovered_device_timestamps is deprecated and will be removed in a future version of habluetooth, use BaseHaRemoteScanner.discovered_device_timestamps instead 158s assert len(scanner._discovered_device_timestamps) == 0 158s 158s tests/test_base_scanner.py::test_remote_scanner_expires_non_connectable 158s /tmp/autopkgtest.M2nZoP/autopkgtest_tmp/build/tests/test_base_scanner.py:377: FutureWarning: BaseHaRemoteScanner._discovered_device_timestamps is deprecated and will be removed in a future version of habluetooth, use BaseHaRemoteScanner.discovered_device_timestamps instead 158s assert len(scanner._discovered_device_timestamps) == 0 158s 158s -- Docs: https://docs.pytest.org/en/stable/how-to/capture-warnings.html 158s ================== 89 passed, 1 skipped, 29 warnings in 9.58s ================== 158s autopkgtest [03:09:18]: test pybuild-autopkgtest: -----------------------] 159s autopkgtest [03:09:19]: test pybuild-autopkgtest: - - - - - - - - - - results - - - - - - - - - - 159s pybuild-autopkgtest PASS 159s autopkgtest [03:09:19]: @@@@@@@@@@@@@@@@@@@@ summary 159s pybuild-autopkgtest PASS