0s autopkgtest [01:10:23]: starting date: 2024-03-09 0s autopkgtest [01:10:23]: git checkout: d9c0295 adt_testbed.py: supress warnings from apt using a shell pipeline 0s autopkgtest [01:10:23]: host juju-7f2275-prod-proposed-migration-environment-2; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.eq1gx51j/out --timeout-copy=6000 --setup-commands /home/ubuntu/autopkgtest-cloud/worker-config-production/setup-canonical.sh --setup-commands /home/ubuntu/autopkgtest/setup-commands/setup-testbed --apt-pocket=proposed=src:zlib --apt-upgrade libslow5lib --timeout-short=300 --timeout-copy=20000 --timeout-build=20000 --env=ADT_TEST_TRIGGERS=zlib/1:1.3.dfsg-3.1ubuntu1 -- ssh -s /home/ubuntu/autopkgtest/ssh-setup/nova -- --flavor autopkgtest --security-groups autopkgtest-juju-7f2275-prod-proposed-migration-environment-2@bos01-ppc64el-20.secgroup --name adt-noble-ppc64el-libslow5lib-20240309-011023-juju-7f2275-prod-proposed-migration-environment-2 --image adt/ubuntu-noble-ppc64el-server --keyname testbed-juju-7f2275-prod-proposed-migration-environment-2 --net-id=net_prod-proposed-migration -e TERM=linux -e ''"'"'http_proxy=http://squid.internal:3128'"'"'' -e ''"'"'https_proxy=http://squid.internal:3128'"'"'' -e ''"'"'no_proxy=127.0.0.1,127.0.1.1,login.ubuntu.com,localhost,localdomain,novalocal,internal,archive.ubuntu.com,ports.ubuntu.com,security.ubuntu.com,ddebs.ubuntu.com,changelogs.ubuntu.com,launchpadlibrarian.net,launchpadcontent.net,launchpad.net,10.24.0.0/24,keystone.ps5.canonical.com,objectstorage.prodstack5.canonical.com'"'"'' --mirror=http://us.ports.ubuntu.com/ubuntu-ports/ 177s autopkgtest [01:13:20]: @@@@@@@@@@@@@@@@@@@@ test bed setup 178s Get:1 http://ftpmaster.internal/ubuntu noble-proposed InRelease [117 kB] 178s Get:2 http://ftpmaster.internal/ubuntu noble-proposed/multiverse Sources [35.7 kB] 178s Get:3 http://ftpmaster.internal/ubuntu noble-proposed/universe Sources [2547 kB] 179s Get:4 http://ftpmaster.internal/ubuntu noble-proposed/main Sources [437 kB] 179s Get:5 http://ftpmaster.internal/ubuntu noble-proposed/restricted Sources [3976 B] 179s Get:6 http://ftpmaster.internal/ubuntu noble-proposed/main ppc64el Packages [578 kB] 179s Get:7 http://ftpmaster.internal/ubuntu noble-proposed/main ppc64el c-n-f Metadata [3116 B] 179s Get:8 http://ftpmaster.internal/ubuntu noble-proposed/restricted ppc64el Packages [1372 B] 179s Get:9 http://ftpmaster.internal/ubuntu noble-proposed/restricted ppc64el c-n-f Metadata [116 B] 179s Get:10 http://ftpmaster.internal/ubuntu noble-proposed/universe ppc64el Packages [2754 kB] 179s Get:11 http://ftpmaster.internal/ubuntu noble-proposed/universe ppc64el c-n-f Metadata [8652 B] 179s Get:12 http://ftpmaster.internal/ubuntu noble-proposed/multiverse ppc64el Packages [37.0 kB] 179s Get:13 http://ftpmaster.internal/ubuntu noble-proposed/multiverse ppc64el c-n-f Metadata [116 B] 181s Fetched 6522 kB in 2s (3188 kB/s) 182s Reading package lists... 186s Reading package lists... 187s Building dependency tree... 187s Reading state information... 187s Calculating upgrade... 187s The following packages will be upgraded: 187s zlib1g 187s 1 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 187s Need to get 72.8 kB of archives. 187s After this operation, 0 B of additional disk space will be used. 187s Get:1 http://ftpmaster.internal/ubuntu noble-proposed/main ppc64el zlib1g ppc64el 1:1.3.dfsg-3.1ubuntu1 [72.8 kB] 188s Fetched 72.8 kB in 0s (256 kB/s) 188s (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 ... 70107 files and directories currently installed.) 188s Preparing to unpack .../zlib1g_1%3a1.3.dfsg-3.1ubuntu1_ppc64el.deb ... 188s Unpacking zlib1g:ppc64el (1:1.3.dfsg-3.1ubuntu1) over (1:1.3.dfsg-3ubuntu1) ... 188s Setting up zlib1g:ppc64el (1:1.3.dfsg-3.1ubuntu1) ... 188s Processing triggers for libc-bin (2.39-0ubuntu2) ... 188s W: Target Packages (main/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 188s W: Target Packages (main/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 188s W: Target CNF (main/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 188s W: Target CNF (main/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 188s W: Target Packages (universe/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 188s W: Target Packages (universe/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 188s W: Target CNF (universe/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 188s W: Target CNF (universe/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 188s W: Target Packages (restricted/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 188s W: Target Packages (restricted/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 188s W: Target CNF (restricted/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 188s W: Target CNF (restricted/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 188s W: Target Packages (multiverse/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 188s W: Target Packages (multiverse/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 188s W: Target CNF (multiverse/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 188s W: Target CNF (multiverse/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 188s W: Target Packages (main/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 188s W: Target Packages (main/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 188s W: Target CNF (main/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 188s W: Target CNF (main/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 188s W: Target Packages (universe/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 188s W: Target Packages (universe/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 188s W: Target CNF (universe/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 188s W: Target CNF (universe/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 188s W: Target Packages (restricted/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 188s W: Target Packages (restricted/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 188s W: Target CNF (restricted/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 188s W: Target CNF (restricted/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 188s W: Target Packages (multiverse/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 188s W: Target Packages (multiverse/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 188s W: Target CNF (multiverse/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 188s W: Target CNF (multiverse/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 188s W: Target Packages (main/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 188s W: Target Packages (main/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 188s W: Target CNF (main/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 188s W: Target CNF (main/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 188s W: Target Packages (universe/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 188s W: Target Packages (universe/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 188s W: Target CNF (universe/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 188s W: Target CNF (universe/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 188s W: Target Packages (restricted/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 188s W: Target Packages (restricted/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 188s W: Target CNF (restricted/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 188s W: Target CNF (restricted/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 188s W: Target Packages (multiverse/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 188s W: Target Packages (multiverse/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 188s W: Target CNF (multiverse/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 188s W: Target CNF (multiverse/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 188s Reading package lists... 188s Building dependency tree... 188s Reading state information... 188s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 189s sh: Attempting to set up Debian/Ubuntu apt sources automatically 189s sh: Distribution appears to be Ubuntu 193s Reading package lists... 193s Building dependency tree... 193s Reading state information... 193s W: Target Packages (main/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 193s W: Target Packages (main/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 193s W: Target CNF (main/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 193s eatmydata is already the newest version (131-1). 193s dbus is already the newest version (1.14.10-4ubuntu1). 193s dbus set to manually installed. 193s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 193s W: Target CNF (main/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 193s W: Target Packages (universe/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 193s W: Target Packages (universe/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 193s W: Target CNF (universe/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 193s W: Target CNF (universe/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 193s W: Target Packages (restricted/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 193s W: Target Packages (restricted/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 193s W: Target CNF (restricted/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 193s W: Target CNF (restricted/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 193s W: Target Packages (multiverse/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 193s W: Target Packages (multiverse/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 193s W: Target CNF (multiverse/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 193s W: Target CNF (multiverse/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 193s W: Target Packages (main/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 193s W: Target Packages (main/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 193s W: Target CNF (main/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 193s W: Target CNF (main/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 193s W: Target Packages (universe/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 193s W: Target Packages (universe/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 193s W: Target CNF (universe/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 193s W: Target CNF (universe/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 193s W: Target Packages (restricted/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 193s W: Target Packages (restricted/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 193s W: Target CNF (restricted/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 193s W: Target CNF (restricted/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 193s W: Target Packages (multiverse/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 193s W: Target Packages (multiverse/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 193s W: Target CNF (multiverse/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 193s W: Target CNF (multiverse/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 193s W: Target Packages (main/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 193s W: Target Packages (main/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 193s W: Target CNF (main/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 193s W: Target CNF (main/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 193s W: Target Packages (universe/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 193s W: Target Packages (universe/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 193s W: Target CNF (universe/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 193s W: Target CNF (universe/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 193s W: Target Packages (restricted/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 193s W: Target Packages (restricted/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 193s W: Target CNF (restricted/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 193s W: Target CNF (restricted/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 193s W: Target Packages (multiverse/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 193s W: Target Packages (multiverse/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 193s W: Target CNF (multiverse/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 193s W: Target CNF (multiverse/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 193s Reading package lists... 193s Building dependency tree... 193s Reading state information... 193s rng-tools-debian is already the newest version (2.4). 193s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 194s Reading package lists... 194s Building dependency tree... 194s Reading state information... 194s haveged is already the newest version (1.9.14-1ubuntu1). 194s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 194s Reading package lists... 194s Building dependency tree... 194s Reading state information... 194s The following packages will be REMOVED: 194s cloud-init* python3-configobj* python3-debconf* 195s 0 upgraded, 0 newly installed, 3 to remove and 0 not upgraded. 195s After this operation, 3248 kB disk space will be freed. 195s (Reading database ... (Reading database ... 5% (Reading database ... 10% (Reading database ... 15% (Reading database ... 20% (Reading database ... 25% (Reading database ... 30% (Reading database ... 35% (Reading database ... 40% (Reading database ... 45% (Reading database ... 50% (Reading database ... 55% (Reading database ... 60% (Reading database ... 65% (Reading database ... 70% (Reading database ... 75% (Reading database ... 80% (Reading database ... 85% (Reading database ... 90% (Reading database ... 95% (Reading database ... 100% (Reading database ... 70107 files and directories currently installed.) 195s Removing cloud-init (24.1-0ubuntu1) ... 195s Removing python3-configobj (5.0.8-3) ... 195s Removing python3-debconf (1.5.86) ... 195s Processing triggers for man-db (2.12.0-3) ... 196s (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 ... 69718 files and directories currently installed.) 196s Purging configuration files for cloud-init (24.1-0ubuntu1) ... 197s dpkg: warning: while removing cloud-init, directory '/etc/cloud/cloud.cfg.d' not empty so not removed 197s Processing triggers for rsyslog (8.2312.0-3ubuntu3) ... 197s Reading package lists... 197s Building dependency tree... 197s Reading state information... 197s linux-generic is already the newest version (6.8.0-11.11+1). 197s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 198s Hit:1 http://ftpmaster.internal/ubuntu noble InRelease 198s Hit:2 http://ftpmaster.internal/ubuntu noble-updates InRelease 198s Hit:3 http://ftpmaster.internal/ubuntu noble-security InRelease 199s Hit:4 http://ftpmaster.internal/ubuntu noble-proposed InRelease 199s Hit:5 http://ftpmaster.internal/ubuntu noble-backports InRelease 202s Reading package lists... 202s W: Target Packages (main/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target Packages (main/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target CNF (main/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target CNF (main/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target Packages (universe/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target Packages (universe/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target CNF (universe/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target CNF (universe/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target Packages (restricted/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target Packages (restricted/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target CNF (restricted/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target CNF (restricted/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target Packages (multiverse/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target Packages (multiverse/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target CNF (multiverse/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target CNF (multiverse/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target Packages (main/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target Packages (main/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target CNF (main/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target CNF (main/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target Packages (universe/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target Packages (universe/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target CNF (universe/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target CNF (universe/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target Packages (restricted/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target Packages (restricted/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target CNF (restricted/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target CNF (restricted/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target Packages (multiverse/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target Packages (multiverse/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target CNF (multiverse/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target CNF (multiverse/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target Packages (main/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 202s W: Target Packages (main/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 202s W: Target CNF (main/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 202s W: Target CNF (main/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 202s W: Target Packages (universe/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 202s W: Target Packages (universe/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 202s W: Target CNF (universe/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 202s W: Target CNF (universe/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 202s W: Target Packages (restricted/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 202s W: Target Packages (restricted/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 202s W: Target CNF (restricted/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 202s W: Target CNF (restricted/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 202s W: Target Packages (multiverse/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 202s W: Target Packages (multiverse/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 202s W: Target CNF (multiverse/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 202s W: Target CNF (multiverse/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 202s W: Target Packages (main/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target Packages (main/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target CNF (main/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target CNF (main/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target Packages (universe/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target Packages (universe/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target CNF (universe/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target CNF (universe/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target Packages (restricted/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target Packages (restricted/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target CNF (restricted/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target CNF (restricted/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target Packages (multiverse/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target Packages (multiverse/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target CNF (multiverse/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target CNF (multiverse/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target Packages (main/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target Packages (main/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target CNF (main/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target CNF (main/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target Packages (universe/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target Packages (universe/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target CNF (universe/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target CNF (universe/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target Packages (restricted/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target Packages (restricted/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target CNF (restricted/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target CNF (restricted/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target Packages (multiverse/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target Packages (multiverse/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target CNF (multiverse/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target CNF (multiverse/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 202s W: Target Packages (main/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 202s W: Target Packages (main/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 202s W: Target CNF (main/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 202s W: Target CNF (main/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 202s W: Target Packages (universe/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 202s W: Target Packages (universe/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 202s W: Target CNF (universe/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 202s W: Target CNF (universe/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 202s W: Target Packages (restricted/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 202s W: Target Packages (restricted/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 202s W: Target CNF (restricted/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 202s W: Target CNF (restricted/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 202s W: Target Packages (multiverse/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 202s W: Target Packages (multiverse/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 202s W: Target CNF (multiverse/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 202s W: Target CNF (multiverse/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 202s Reading package lists... 203s Building dependency tree... 203s Reading state information... 203s Calculating upgrade... 203s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 203s Reading package lists... 203s Building dependency tree... 203s Reading state information... 203s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 204s autopkgtest [01:13:47]: rebooting testbed after setup commands that affected boot 373s autopkgtest [01:16:36]: testbed running kernel: Linux 6.8.0-11-generic #11-Ubuntu SMP Wed Feb 14 00:33:03 UTC 2024 373s autopkgtest [01:16:36]: testbed dpkg architecture: ppc64el 378s autopkgtest [01:16:41]: @@@@@@@@@@@@@@@@@@@@ apt-source libslow5lib 378s W: Target Packages (main/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 378s W: Target Packages (main/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 378s W: Target CNF (main/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 378s W: Target CNF (main/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 378s W: Target Packages (universe/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 378s W: Target Packages (universe/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 378s W: Target CNF (universe/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 378s W: Target CNF (universe/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 378s W: Target Packages (restricted/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 378s W: Target Packages (restricted/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 378s W: Target CNF (restricted/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 378s W: Target CNF (restricted/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 378s W: Target Packages (multiverse/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 378s W: Target Packages (multiverse/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 378s W: Target CNF (multiverse/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 378s W: Target CNF (multiverse/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 378s W: Target Packages (main/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 378s W: Target Packages (main/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 378s W: Target CNF (main/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 378s W: Target CNF (main/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 378s W: Target Packages (universe/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 378s W: Target Packages (universe/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 378s W: Target CNF (universe/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 378s W: Target CNF (universe/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 378s W: Target Packages (restricted/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 378s W: Target Packages (restricted/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 378s W: Target CNF (restricted/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 378s W: Target CNF (restricted/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 378s W: Target Packages (multiverse/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 378s W: Target Packages (multiverse/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 378s W: Target CNF (multiverse/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 378s W: Target CNF (multiverse/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 378s W: Target Packages (main/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 378s W: Target Packages (main/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 378s W: Target CNF (main/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 378s W: Target CNF (main/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 378s W: Target Packages (universe/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 378s W: Target Packages (universe/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 378s W: Target CNF (universe/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 378s W: Target CNF (universe/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 378s W: Target Packages (restricted/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 378s W: Target Packages (restricted/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 378s W: Target CNF (restricted/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 378s W: Target CNF (restricted/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 378s W: Target Packages (multiverse/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 378s W: Target Packages (multiverse/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 378s W: Target CNF (multiverse/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 378s W: Target CNF (multiverse/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 380s Get:1 http://ftpmaster.internal/ubuntu noble/universe libslow5lib 0.7.0+dfsg-2ubuntu4 (dsc) [2580 B] 380s Get:2 http://ftpmaster.internal/ubuntu noble/universe libslow5lib 0.7.0+dfsg-2ubuntu4 (tar) [2014 kB] 380s Get:3 http://ftpmaster.internal/ubuntu noble/universe libslow5lib 0.7.0+dfsg-2ubuntu4 (diff) [8240 B] 380s gpgv: Signature made Tue Nov 14 20:48:17 2023 UTC 380s gpgv: using RSA key 25E3FF2D7F469DBE7D0D4E50AFCFEC8E669CE1C2 380s gpgv: Can't check signature: No public key 380s dpkg-source: warning: cannot verify inline signature for ./libslow5lib_0.7.0+dfsg-2ubuntu4.dsc: no acceptable signature found 380s autopkgtest [01:16:43]: testing package libslow5lib version 0.7.0+dfsg-2ubuntu4 380s autopkgtest [01:16:43]: build not needed 384s autopkgtest [01:16:47]: test run-pybinding-test: preparing testbed 386s Reading package lists... 386s Building dependency tree... 386s Reading state information... 387s Correcting dependencies...Starting pkgProblemResolver with broken count: 0 387s Starting 2 pkgProblemResolver with broken count: 0 387s Done 387s Done 387s Starting pkgProblemResolver with broken count: 0 387s Starting 2 pkgProblemResolver with broken count: 0 387s Done 387s The following additional packages will be installed: 387s libblas3 libgfortran5 liblapack3 libslow5-0 libslow5-dev libstreamvbyte0 387s python3-all python3-numpy python3-slow5 387s Suggested packages: 387s gcc gfortran python3-dev python3-pytest 387s The following NEW packages will be installed: 387s libblas3 libgfortran5 liblapack3 libslow5-0 libslow5-dev libstreamvbyte0 387s python3-all python3-numpy python3-slow5 387s 0 upgraded, 9 newly installed, 0 to remove and 0 not upgraded. 387s 1 not fully installed or removed. 387s Need to get 10.0 MB of archives. 387s After this operation, 56.2 MB of additional disk space will be used. 387s Get:1 http://ftpmaster.internal/ubuntu noble/universe ppc64el libslow5-0 ppc64el 0.7.0+dfsg-2ubuntu4 [69.2 kB] 388s Get:2 http://ftpmaster.internal/ubuntu noble/universe ppc64el libslow5-dev ppc64el 0.7.0+dfsg-2ubuntu4 [102 kB] 388s Get:3 http://ftpmaster.internal/ubuntu noble/universe ppc64el libstreamvbyte0 ppc64el 0.4.1-4ubuntu1 [6400 B] 388s Get:4 http://ftpmaster.internal/ubuntu noble/main ppc64el libblas3 ppc64el 3.12.0-3 [227 kB] 388s Get:5 http://ftpmaster.internal/ubuntu noble/main ppc64el libgfortran5 ppc64el 14-20240303-1ubuntu1 [574 kB] 388s Get:6 http://ftpmaster.internal/ubuntu noble/main ppc64el liblapack3 ppc64el 3.12.0-3 [2804 kB] 389s Get:7 http://ftpmaster.internal/ubuntu noble/main ppc64el python3-numpy ppc64el 1:1.24.2-2 [5581 kB] 390s Get:8 http://ftpmaster.internal/ubuntu noble/universe ppc64el python3-slow5 ppc64el 0.7.0+dfsg-2ubuntu4 [645 kB] 390s Get:9 http://ftpmaster.internal/ubuntu noble/main ppc64el python3-all ppc64el 3.12.1-0ubuntu2 [904 B] 390s Fetched 10.0 MB in 3s (3524 kB/s) 390s Selecting previously unselected package libslow5-0:ppc64el. 391s (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 ... 69663 files and directories currently installed.) 391s Preparing to unpack .../0-libslow5-0_0.7.0+dfsg-2ubuntu4_ppc64el.deb ... 391s Unpacking libslow5-0:ppc64el (0.7.0+dfsg-2ubuntu4) ... 391s Selecting previously unselected package libslow5-dev:ppc64el. 391s Preparing to unpack .../1-libslow5-dev_0.7.0+dfsg-2ubuntu4_ppc64el.deb ... 391s Unpacking libslow5-dev:ppc64el (0.7.0+dfsg-2ubuntu4) ... 391s Selecting previously unselected package libstreamvbyte0:ppc64el. 391s Preparing to unpack .../2-libstreamvbyte0_0.4.1-4ubuntu1_ppc64el.deb ... 391s Unpacking libstreamvbyte0:ppc64el (0.4.1-4ubuntu1) ... 391s Selecting previously unselected package libblas3:ppc64el. 391s Preparing to unpack .../3-libblas3_3.12.0-3_ppc64el.deb ... 391s Unpacking libblas3:ppc64el (3.12.0-3) ... 391s Selecting previously unselected package libgfortran5:ppc64el. 391s Preparing to unpack .../4-libgfortran5_14-20240303-1ubuntu1_ppc64el.deb ... 391s Unpacking libgfortran5:ppc64el (14-20240303-1ubuntu1) ... 391s Selecting previously unselected package liblapack3:ppc64el. 391s Preparing to unpack .../5-liblapack3_3.12.0-3_ppc64el.deb ... 391s Unpacking liblapack3:ppc64el (3.12.0-3) ... 391s Selecting previously unselected package python3-numpy. 391s Preparing to unpack .../6-python3-numpy_1%3a1.24.2-2_ppc64el.deb ... 391s Unpacking python3-numpy (1:1.24.2-2) ... 391s Selecting previously unselected package python3-slow5. 391s Preparing to unpack .../7-python3-slow5_0.7.0+dfsg-2ubuntu4_ppc64el.deb ... 391s Unpacking python3-slow5 (0.7.0+dfsg-2ubuntu4) ... 391s Selecting previously unselected package python3-all. 391s Preparing to unpack .../8-python3-all_3.12.1-0ubuntu2_ppc64el.deb ... 391s Unpacking python3-all (3.12.1-0ubuntu2) ... 391s Setting up libstreamvbyte0:ppc64el (0.4.1-4ubuntu1) ... 391s Setting up python3-all (3.12.1-0ubuntu2) ... 391s Setting up libblas3:ppc64el (3.12.0-3) ... 391s update-alternatives: using /usr/lib/powerpc64le-linux-gnu/blas/libblas.so.3 to provide /usr/lib/powerpc64le-linux-gnu/libblas.so.3 (libblas.so.3-powerpc64le-linux-gnu) in auto mode 391s Setting up libslow5-0:ppc64el (0.7.0+dfsg-2ubuntu4) ... 391s Setting up libgfortran5:ppc64el (14-20240303-1ubuntu1) ... 391s Setting up liblapack3:ppc64el (3.12.0-3) ... 391s update-alternatives: using /usr/lib/powerpc64le-linux-gnu/lapack/liblapack.so.3 to provide /usr/lib/powerpc64le-linux-gnu/liblapack.so.3 (liblapack.so.3-powerpc64le-linux-gnu) in auto mode 391s Setting up libslow5-dev:ppc64el (0.7.0+dfsg-2ubuntu4) ... 391s Setting up python3-numpy (1:1.24.2-2) ... 393s Setting up python3-slow5 (0.7.0+dfsg-2ubuntu4) ... 393s Setting up autopkgtest-satdep (0) ... 393s Processing triggers for man-db (2.12.0-3) ... 393s Processing triggers for libc-bin (2.39-0ubuntu2) ... 396s (Reading database ... 70722 files and directories currently installed.) 396s Removing autopkgtest-satdep (0) ... 397s autopkgtest [01:17:00]: test run-pybinding-test: [----------------------- 397s Testing with python3.12 in /tmp/autopkgtest.JR7qig/autopkgtest_tmp: 397s 09-Mar-24 01:17:00 - [DEBUG]: FILE: examples/example.slow5, mode: r 397s 09-Mar-24 01:17:00 - [DEBUG]: FILE: b'examples/example.slow5', mode: b'r' 397s 09-Mar-24 01:17:00 - [DEBUG]: Number of read_groups: 1 397s 09-Mar-24 01:17:00 - [DEBUG]: FILE: examples/example.slow5, mode: r 397s 09-Mar-24 01:17:00 - [DEBUG]: Creating/loading index... 397s [slow5_idx_init::INFO] Index file not found. Creating an index at 'examples/example.slow5.idx'. 397s 09-Mar-24 01:17:00 - [DEBUG]: get_aux_names starting 397s 09-Mar-24 01:17:00 - [DEBUG]: get_aux_names aux_len: 0 397s 09-Mar-24 01:17:00 - [WARNING]: get_aux_names ret is NULL 397s 09-Mar-24 01:17:00 - [DEBUG]: get_aux_types starting 397s 09-Mar-24 01:17:00 - [DEBUG]: get_aux_types aux_len: 0 397s 09-Mar-24 01:17:00 - [WARNING]: get_aux_types self.s5_aux_type is NULL 397s 09-Mar-24 01:17:00 - [WARNING]: get_read unknown aux name: read_number 397s 09-Mar-24 01:17:00 - [WARNING]: get_read unknown aux name: blah 397s 09-Mar-24 01:17:00 - [WARNING]: get_read unknown aux name: start_mux 397s 09-Mar-24 01:17:00 - [DEBUG]: slow5_get_next return: 0 397s 09-Mar-24 01:17:00 - [DEBUG]: slow5_get_next return: 0 397s 09-Mar-24 01:17:00 - [DEBUG]: slow5_get_next return: 0 397s 09-Mar-24 01:17:00 - [DEBUG]: slow5_get_next return: 0 397s 09-Mar-24 01:17:00 - [DEBUG]: slow5_get_next return: 0 397s 09-Mar-24 01:17:00 - [DEBUG]: slow5_get_next return: -1 397s 09-Mar-24 01:17:00 - [DEBUG]: slow5_get_next reached end of file (EOF)(-1): -1: ['SLOW5_ERR_EOF', 'End Of File reached'] 398s [slow5_idx_get::ERROR] Read ID 'null_read' was not found. At src/slow5_idx.c:441 398s 09-Mar-24 01:17:00 - [DEBUG]: get_read return not 0: -7 398s 09-Mar-24 01:17:00 - [DEBUG]: slow5_get_hdr_keys head_len: 32 398s 09-Mar-24 01:17:00 - [DEBUG]: slow5_get_hdr_keys head_len: 32 398s 09-Mar-24 01:17:00 - [DEBUG]: examples/example.slow5 closed 398s 09-Mar-24 01:17:00 - [DEBUG]: FILE: examples/example2.slow5, mode: r 398s 09-Mar-24 01:17:00 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r' 398s 09-Mar-24 01:17:00 - [DEBUG]: Number of read_groups: 4 398s 09-Mar-24 01:17:00 - [DEBUG]: FILE: examples/example2.slow5, mode: r 398s 09-Mar-24 01:17:00 - [DEBUG]: Creating/loading index... 398s [slow5_idx_init::INFO] Index file not found. Creating an index at 'examples/example2.slow5.idx'. 398s 09-Mar-24 01:17:00 - [DEBUG]: get_aux_names starting 398s 09-Mar-24 01:17:00 - [DEBUG]: get_aux_names aux_len: 5 398s 09-Mar-24 01:17:00 - [DEBUG]: get_aux_types starting 398s 09-Mar-24 01:17:00 - [DEBUG]: get_aux_types aux_len: 5 398s 09-Mar-24 01:17:00 - [WARNING]: get_read unknown aux name: blah 398s 09-Mar-24 01:17:00 - [WARNING]: get_read unknown aux name: blah 398s 09-Mar-24 01:17:00 - [DEBUG]: get_aux_names starting 398s 09-Mar-24 01:17:00 - [DEBUG]: get_aux_names aux_len: 5 398s 09-Mar-24 01:17:00 - [DEBUG]: get_aux_types starting 398s 09-Mar-24 01:17:00 - [DEBUG]: get_aux_types aux_len: 5 398s 09-Mar-24 01:17:00 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:00 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:00 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:00 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:00 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:00 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:00 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:00 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:00 - [DEBUG]: slow5_get_next return: -1 398s 09-Mar-24 01:17:00 - [DEBUG]: slow5_get_next reached end of file (EOF)(-1): -1: ['SLOW5_ERR_EOF', 'End Of File reached'] 398s 09-Mar-24 01:17:00 - [DEBUG]: examples/example2.slow5 closed 398s 09-Mar-24 01:17:00 - [DEBUG]: FILE: examples/example_write.slow5, mode: w 398s 09-Mar-24 01:17:00 - [DEBUG]: FILE: b'examples/example_write.slow5', mode: b'w' 398s 09-Mar-24 01:17:00 - [DEBUG]: Not writing blow5, skipping compression steps 398s 09-Mar-24 01:17:00 - [DEBUG]: FILE: examples/example2.slow5, mode: r 398s 09-Mar-24 01:17:00 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r' 398s 09-Mar-24 01:17:00 - [DEBUG]: Number of read_groups: 4 398s 09-Mar-24 01:17:00 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: _record_type_validation running 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: _record_type_validation done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: checking header stuff... 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: writting header... 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: header written 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_rec_init() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write assignments... 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write assignments done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write processing raw_signal 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write raw_signal done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_write() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_write() ret: 305872 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_rec_free() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: function complete, returning 0 398s 09-Mar-24 01:17:00 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: _record_type_validation running 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: _record_type_validation done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_rec_init() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write assignments... 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write assignments done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write processing raw_signal 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write raw_signal done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_write() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_write() ret: 152707 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_rec_free() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: function complete, returning 0 398s 09-Mar-24 01:17:00 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: _record_type_validation running 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: _record_type_validation done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_rec_init() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write assignments... 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write assignments done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write processing raw_signal 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write raw_signal done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_write() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_write() ret: 305872 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_rec_free() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: function complete, returning 0 398s 09-Mar-24 01:17:00 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: _record_type_validation running 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: _record_type_validation done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_rec_init() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write assignments... 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write assignments done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write processing raw_signal 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write raw_signal done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_write() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_write() ret: 152707 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_rec_free() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: function complete, returning 0 398s 09-Mar-24 01:17:00 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: _record_type_validation running 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: _record_type_validation done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_rec_init() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write assignments... 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write assignments done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write processing raw_signal 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write raw_signal done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_write() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_write() ret: 305872 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_rec_free() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: function complete, returning 0 398s 09-Mar-24 01:17:00 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: _record_type_validation running 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: _record_type_validation done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_rec_init() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write assignments... 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write assignments done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write processing raw_signal 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write raw_signal done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_write() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_write() ret: 152707 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_rec_free() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: function complete, returning 0 398s 09-Mar-24 01:17:00 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: _record_type_validation running 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: _record_type_validation done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_rec_init() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write assignments... 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write assignments done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write processing raw_signal 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write raw_signal done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_write() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_write() ret: 305906 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_rec_free() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: function complete, returning 0 398s 09-Mar-24 01:17:00 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: _record_type_validation running 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: _record_type_validation done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_rec_init() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write assignments... 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write assignments done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write processing raw_signal 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write raw_signal done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_write() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_write() ret: 152741 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_rec_free() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: function complete, returning 0 398s 09-Mar-24 01:17:00 - [DEBUG]: slow5_get_next return: -1 398s 09-Mar-24 01:17:00 - [DEBUG]: slow5_get_next reached end of file (EOF)(-1): -1: ['SLOW5_ERR_EOF', 'End Of File reached'] 398s 09-Mar-24 01:17:00 - [DEBUG]: examples/example_write.slow5 closed 398s 09-Mar-24 01:17:00 - [DEBUG]: examples/example2.slow5 closed 398s 09-Mar-24 01:17:00 - [DEBUG]: FILE: examples/example_write_append.blow5, mode: w 398s 09-Mar-24 01:17:00 - [DEBUG]: FILE: b'examples/example_write_append.blow5', mode: b'w' 398s 09-Mar-24 01:17:00 - [DEBUG]: examples/example_write.slow5 already closed 398s 09-Mar-24 01:17:00 - [DEBUG]: pathname: examples/example_write.slow5 398s 09-Mar-24 01:17:00 - [DEBUG]: total_time_slow5_get_next: 0.0 seconds 398s 09-Mar-24 01:17:00 - [DEBUG]: total_time_yield_reads: 0.0 seconds 398s 09-Mar-24 01:17:00 - [DEBUG]: total_single_write_time: 0.02624654769897461 seconds 398s 09-Mar-24 01:17:00 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 398s 09-Mar-24 01:17:00 - [DEBUG]: total_multi_write_time: 0.0 seconds 398s 09-Mar-24 01:17:00 - [DEBUG]: FILE: examples/example2.slow5, mode: r 398s 09-Mar-24 01:17:00 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r' 398s 09-Mar-24 01:17:00 - [DEBUG]: Number of read_groups: 4 398s 09-Mar-24 01:17:00 - [DEBUG]: pathname: examples/example2.slow5 398s 09-Mar-24 01:17:00 - [DEBUG]: total_time_slow5_get_next: 0.022345304489135742 seconds 398s 09-Mar-24 01:17:00 - [DEBUG]: total_time_yield_reads: 0.02320551872253418 seconds 398s 09-Mar-24 01:17:00 - [DEBUG]: total_single_write_time: 0.0 seconds 398s 09-Mar-24 01:17:00 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 398s 09-Mar-24 01:17:00 - [DEBUG]: total_multi_write_time: 0.0 seconds 398s 09-Mar-24 01:17:00 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: _record_type_validation running 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: _record_type_validation done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: checking header stuff... 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: writting header... 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: header written 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_rec_init() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write assignments... 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write assignments done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write processing raw_signal 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write raw_signal done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_write() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_write() ret: 152976 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_rec_free() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: function complete, returning 0 398s 09-Mar-24 01:17:00 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: _record_type_validation running 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: _record_type_validation done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_rec_init() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write assignments... 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write assignments done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write processing raw_signal 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write raw_signal done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_write() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_write() ret: 76384 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_rec_free() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: function complete, returning 0 398s 09-Mar-24 01:17:00 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: _record_type_validation running 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: _record_type_validation done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_rec_init() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write assignments... 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write assignments done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write processing raw_signal 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write raw_signal done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_write() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_write() ret: 152976 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_rec_free() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: function complete, returning 0 398s 09-Mar-24 01:17:00 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: _record_type_validation running 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: _record_type_validation done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_rec_init() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write assignments... 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write assignments done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write processing raw_signal 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write raw_signal done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_write() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_write() ret: 76384 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_rec_free() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: function complete, returning 0 398s 09-Mar-24 01:17:00 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: _record_type_validation running 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: _record_type_validation done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_rec_init() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write assignments... 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write assignments done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write processing raw_signal 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write raw_signal done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_write() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_write() ret: 152976 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_rec_free() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: function complete, returning 0 398s 09-Mar-24 01:17:00 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: _record_type_validation running 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: _record_type_validation done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_rec_init() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write assignments... 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write assignments done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write processing raw_signal 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write raw_signal done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_write() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_write() ret: 76384 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_rec_free() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: function complete, returning 0 398s 09-Mar-24 01:17:00 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: _record_type_validation running 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: _record_type_validation done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_rec_init() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write assignments... 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write assignments done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write processing raw_signal 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write raw_signal done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_write() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_write() ret: 153010 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_rec_free() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: function complete, returning 0 398s 09-Mar-24 01:17:00 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: _record_type_validation running 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: _record_type_validation done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_rec_init() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write assignments... 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write assignments done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write processing raw_signal 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write raw_signal done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_write() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_write() ret: 76418 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_rec_free() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: function complete, returning 0 398s 09-Mar-24 01:17:00 - [DEBUG]: slow5_get_next return: -1 398s 09-Mar-24 01:17:00 - [DEBUG]: slow5_get_next reached end of file (EOF)(-1): -1: ['SLOW5_ERR_EOF', 'End Of File reached'] 398s 09-Mar-24 01:17:00 - [DEBUG]: examples/example2.slow5 closed 398s 09-Mar-24 01:17:00 - [DEBUG]: examples/example_write_append.blow5 closed 398s 09-Mar-24 01:17:00 - [DEBUG]: FILE: examples/example_write_append.blow5, mode: a 398s 09-Mar-24 01:17:00 - [DEBUG]: FILE: b'examples/example_write_append.blow5', mode: b'a' 398s 09-Mar-24 01:17:00 - [DEBUG]: slow5_get_hdr_keys head_len: 38 398s 09-Mar-24 01:17:00 - [DEBUG]: FILE: examples/example2.slow5, mode: r 398s 09-Mar-24 01:17:00 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r' 398s 09-Mar-24 01:17:00 - [DEBUG]: Number of read_groups: 4 398s 09-Mar-24 01:17:00 - [DEBUG]: pathname: examples/example2.slow5 398s 09-Mar-24 01:17:00 - [DEBUG]: total_time_slow5_get_next: 0.022422313690185547 seconds 398s 09-Mar-24 01:17:00 - [DEBUG]: total_time_yield_reads: 0.023252010345458984 seconds 398s 09-Mar-24 01:17:00 - [DEBUG]: total_single_write_time: 0.0 seconds 398s 09-Mar-24 01:17:00 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 398s 09-Mar-24 01:17:00 - [DEBUG]: total_multi_write_time: 0.0 seconds 398s 09-Mar-24 01:17:00 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: _record_type_validation running 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: _record_type_validation done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_rec_init() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write assignments... 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write assignments done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write processing raw_signal 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write raw_signal done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_write() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_write() ret: 152983 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_rec_free() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: function complete, returning 0 398s 09-Mar-24 01:17:00 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: _record_type_validation running 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: _record_type_validation done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_rec_init() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write assignments... 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write assignments done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write processing raw_signal 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write raw_signal done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_write() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_write() ret: 76391 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_rec_free() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: function complete, returning 0 398s 09-Mar-24 01:17:00 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: _record_type_validation running 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: _record_type_validation done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_rec_init() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write assignments... 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write assignments done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write processing raw_signal 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write raw_signal done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_write() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_write() ret: 152983 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_rec_free() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: function complete, returning 0 398s 09-Mar-24 01:17:00 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: _record_type_validation running 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: _record_type_validation done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_rec_init() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write assignments... 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write assignments done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write processing raw_signal 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write raw_signal done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_write() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_write() ret: 76391 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_rec_free() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: function complete, returning 0 398s 09-Mar-24 01:17:00 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: _record_type_validation running 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: _record_type_validation done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_rec_init() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write assignments... 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write assignments done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write processing raw_signal 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write raw_signal done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_write() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_write() ret: 152983 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_rec_free() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: function complete, returning 0 398s 09-Mar-24 01:17:00 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: _record_type_validation running 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: _record_type_validation done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_rec_init() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write assignments... 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write assignments done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write processing raw_signal 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write raw_signal done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_write() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_write() ret: 76391 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_rec_free() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: function complete, returning 0 398s 09-Mar-24 01:17:00 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: _record_type_validation running 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: _record_type_validation done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: slow5_rec_init() 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write assignments... 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write assignments done 398s 09-Mar-24 01:17:00 - [DEBUG]: write_record: self.write processing raw_signal 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write raw_signal done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() ret: 153017 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_rec_free() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: function complete, returning 0 398s 09-Mar-24 01:17:01 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: _record_type_validation running 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: _record_type_validation done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_rec_init() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write assignments... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write assignments done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write processing raw_signal 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write raw_signal done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() ret: 76425 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_rec_free() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: function complete, returning 0 398s 09-Mar-24 01:17:01 - [DEBUG]: slow5_get_next return: -1 398s 09-Mar-24 01:17:01 - [DEBUG]: slow5_get_next reached end of file (EOF)(-1): -1: ['SLOW5_ERR_EOF', 'End Of File reached'] 398s 09-Mar-24 01:17:01 - [DEBUG]: examples/example2.slow5 closed 398s 09-Mar-24 01:17:01 - [DEBUG]: examples/example_write_append.blow5 closed 398s 09-Mar-24 01:17:01 - [DEBUG]: FILE: examples/example_write_aux.blow5, mode: w 398s 09-Mar-24 01:17:01 - [DEBUG]: FILE: b'examples/example_write_aux.blow5', mode: b'w' 398s 09-Mar-24 01:17:01 - [DEBUG]: examples/example_write_append.blow5 already closed 398s 09-Mar-24 01:17:01 - [DEBUG]: pathname: examples/example_write_append.blow5 398s 09-Mar-24 01:17:01 - [DEBUG]: total_time_slow5_get_next: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_time_yield_reads: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_single_write_time: 0.026823997497558594 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_multi_write_time: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: FILE: examples/example2.slow5, mode: r 398s 09-Mar-24 01:17:01 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r' 398s 09-Mar-24 01:17:01 - [DEBUG]: Number of read_groups: 4 398s 09-Mar-24 01:17:01 - [DEBUG]: pathname: examples/example2.slow5 398s 09-Mar-24 01:17:01 - [DEBUG]: total_time_slow5_get_next: 0.022984027862548828 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_time_yield_reads: 0.023953914642333984 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_single_write_time: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_multi_write_time: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:01 - [DEBUG]: get_aux_names starting 398s 09-Mar-24 01:17:01 - [DEBUG]: get_aux_names aux_len: 5 398s 09-Mar-24 01:17:01 - [DEBUG]: get_aux_types starting 398s 09-Mar-24 01:17:01 - [DEBUG]: get_aux_types aux_len: 5 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: _record_type_validation running 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: _record_type_validation done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checking header stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: writting header... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: header written 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_rec_init() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write assignments... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write assignments done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write processing raw_signal 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write raw_signal done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: channel_number: 281 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string running... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string type: 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: median_before: 231.363533 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: read_number: 4019 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: start_mux: 1 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: start_time: 78470500 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: aux stuff done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() ret: 67258 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_rec_free() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: function complete, returning 0 398s 09-Mar-24 01:17:01 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: _record_type_validation running 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: _record_type_validation done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_rec_init() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write assignments... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write assignments done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write processing raw_signal 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write raw_signal done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: channel_number: 391 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string running... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string type: 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: median_before: 260.557264 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: read_number: 2287 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: start_mux: 2 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: start_time: 36886851 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: aux stuff done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() ret: 32408 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_rec_free() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: function complete, returning 0 398s 09-Mar-24 01:17:01 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: _record_type_validation running 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: _record_type_validation done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_rec_init() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write assignments... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write assignments done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write processing raw_signal 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write raw_signal done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: channel_number: 281 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string running... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string type: 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: median_before: 231.363533 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: read_number: 4019 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: start_mux: 1 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: start_time: 78470500 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: aux stuff done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() ret: 67258 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_rec_free() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: function complete, returning 0 398s 09-Mar-24 01:17:01 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: _record_type_validation running 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: _record_type_validation done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_rec_init() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write assignments... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write assignments done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write processing raw_signal 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write raw_signal done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: channel_number: 391 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string running... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string type: 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: median_before: 260.557264 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: read_number: 2287 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: start_mux: 2 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: start_time: 36886851 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: aux stuff done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() ret: 32408 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_rec_free() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: function complete, returning 0 398s 09-Mar-24 01:17:01 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: _record_type_validation running 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: _record_type_validation done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_rec_init() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write assignments... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write assignments done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write processing raw_signal 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write raw_signal done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: channel_number: 281 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string running... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string type: 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: median_before: 231.363533 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: read_number: 4019 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: start_mux: 1 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: start_time: 78470500 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: aux stuff done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() ret: 67260 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_rec_free() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: function complete, returning 0 398s 09-Mar-24 01:17:01 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: _record_type_validation running 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: _record_type_validation done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_rec_init() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write assignments... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write assignments done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write processing raw_signal 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write raw_signal done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: channel_number: 391 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string running... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string type: 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: median_before: 260.557264 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: read_number: 2287 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: start_mux: 2 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: start_time: 36886851 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: aux stuff done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() ret: 32408 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_rec_free() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: function complete, returning 0 398s 09-Mar-24 01:17:01 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: _record_type_validation running 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: _record_type_validation done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_rec_init() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write assignments... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write assignments done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write processing raw_signal 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write raw_signal done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: channel_number: 281 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string running... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string type: 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: median_before: 231.363533 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: read_number: 4019 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: start_mux: 1 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: start_time: 78470500 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: aux stuff done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() ret: 67298 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_rec_free() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: function complete, returning 0 398s 09-Mar-24 01:17:01 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: _record_type_validation running 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: _record_type_validation done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_rec_init() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write assignments... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write assignments done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write processing raw_signal 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write raw_signal done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: channel_number: 391 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string running... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string type: 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: median_before: 260.557264 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: read_number: 2287 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: start_mux: 2 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: start_time: 36886851 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: aux stuff done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() ret: 32446 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_rec_free() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: function complete, returning 0 398s 09-Mar-24 01:17:01 - [DEBUG]: slow5_get_next return: -1 398s 09-Mar-24 01:17:01 - [DEBUG]: slow5_get_next reached end of file (EOF)(-1): -1: ['SLOW5_ERR_EOF', 'End Of File reached'] 398s 09-Mar-24 01:17:01 - [DEBUG]: examples/example2.slow5 closed 398s 09-Mar-24 01:17:01 - [DEBUG]: examples/example_write_aux.blow5 closed 398s 09-Mar-24 01:17:01 - [DEBUG]: FILE: examples/example_write_append_aux.blow5, mode: w 398s 09-Mar-24 01:17:01 - [DEBUG]: FILE: b'examples/example_write_append_aux.blow5', mode: b'w' 398s 09-Mar-24 01:17:01 - [DEBUG]: examples/example_write_aux.blow5 already closed 398s 09-Mar-24 01:17:01 - [DEBUG]: pathname: examples/example_write_aux.blow5 398s 09-Mar-24 01:17:01 - [DEBUG]: total_time_slow5_get_next: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_time_yield_reads: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_single_write_time: 0.02696394920349121 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_multi_write_time: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: FILE: examples/example2.slow5, mode: r 398s 09-Mar-24 01:17:01 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r' 398s 09-Mar-24 01:17:01 - [DEBUG]: Number of read_groups: 4 398s 09-Mar-24 01:17:01 - [DEBUG]: pathname: examples/example2.slow5 398s 09-Mar-24 01:17:01 - [DEBUG]: total_time_slow5_get_next: 0.023122787475585938 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_time_yield_reads: 0.025154829025268555 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_single_write_time: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_multi_write_time: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:01 - [DEBUG]: get_aux_names starting 398s 09-Mar-24 01:17:01 - [DEBUG]: get_aux_names aux_len: 5 398s 09-Mar-24 01:17:01 - [DEBUG]: get_aux_types starting 398s 09-Mar-24 01:17:01 - [DEBUG]: get_aux_types aux_len: 5 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: _record_type_validation running 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: _record_type_validation done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checking header stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: writting header... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: header written 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_rec_init() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write assignments... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write assignments done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write processing raw_signal 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write raw_signal done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: channel_number: 281 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string running... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string type: 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: median_before: 231.363533 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: read_number: 4019 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: start_mux: 1 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: start_time: 78470500 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: aux stuff done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() ret: 153008 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_rec_free() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: function complete, returning 0 398s 09-Mar-24 01:17:01 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: _record_type_validation running 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: _record_type_validation done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_rec_init() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write assignments... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write assignments done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write processing raw_signal 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write raw_signal done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: channel_number: 391 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string running... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string type: 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: median_before: 260.557264 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: read_number: 2287 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: start_mux: 2 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: start_time: 36886851 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: aux stuff done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() ret: 76416 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_rec_free() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: function complete, returning 0 398s 09-Mar-24 01:17:01 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: _record_type_validation running 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: _record_type_validation done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_rec_init() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write assignments... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write assignments done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write processing raw_signal 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write raw_signal done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: channel_number: 281 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string running... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string type: 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: median_before: 231.363533 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: read_number: 4019 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: start_mux: 1 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: start_time: 78470500 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: aux stuff done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() ret: 153008 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_rec_free() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: function complete, returning 0 398s 09-Mar-24 01:17:01 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: _record_type_validation running 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: _record_type_validation done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_rec_init() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write assignments... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write assignments done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write processing raw_signal 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write raw_signal done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: channel_number: 391 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string running... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string type: 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: median_before: 260.557264 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: read_number: 2287 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: start_mux: 2 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: start_time: 36886851 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: aux stuff done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() ret: 76416 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_rec_free() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: function complete, returning 0 398s 09-Mar-24 01:17:01 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: _record_type_validation running 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: _record_type_validation done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_rec_init() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write assignments... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write assignments done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write processing raw_signal 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write raw_signal done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: channel_number: 281 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string running... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string type: 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: median_before: 231.363533 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: read_number: 4019 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: start_mux: 1 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: start_time: 78470500 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: aux stuff done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() ret: 153008 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_rec_free() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: function complete, returning 0 398s 09-Mar-24 01:17:01 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: _record_type_validation running 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: _record_type_validation done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_rec_init() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write assignments... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write assignments done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write processing raw_signal 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write raw_signal done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: channel_number: 391 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string running... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string type: 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: median_before: 260.557264 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: read_number: 2287 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: start_mux: 2 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: start_time: 36886851 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: aux stuff done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() ret: 76416 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_rec_free() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: function complete, returning 0 398s 09-Mar-24 01:17:01 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: _record_type_validation running 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: _record_type_validation done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_rec_init() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write assignments... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write assignments done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write processing raw_signal 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write raw_signal done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: channel_number: 281 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string running... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string type: 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: median_before: 231.363533 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: read_number: 4019 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: start_mux: 1 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: start_time: 78470500 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: aux stuff done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() ret: 153042 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_rec_free() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: function complete, returning 0 398s 09-Mar-24 01:17:01 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: _record_type_validation running 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: _record_type_validation done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_rec_init() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write assignments... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write assignments done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write processing raw_signal 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write raw_signal done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: channel_number: 391 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string running... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string type: 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: median_before: 260.557264 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: read_number: 2287 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: start_mux: 2 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: start_time: 36886851 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: aux stuff done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() ret: 76450 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_rec_free() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: function complete, returning 0 398s 09-Mar-24 01:17:01 - [DEBUG]: slow5_get_next return: -1 398s 09-Mar-24 01:17:01 - [DEBUG]: slow5_get_next reached end of file (EOF)(-1): -1: ['SLOW5_ERR_EOF', 'End Of File reached'] 398s 09-Mar-24 01:17:01 - [DEBUG]: examples/example2.slow5 closed 398s 09-Mar-24 01:17:01 - [DEBUG]: examples/example_write_append_aux.blow5 closed 398s 09-Mar-24 01:17:01 - [DEBUG]: FILE: examples/example_write_append_aux.blow5, mode: a 398s 09-Mar-24 01:17:01 - [DEBUG]: FILE: b'examples/example_write_append_aux.blow5', mode: b'a' 398s 09-Mar-24 01:17:01 - [DEBUG]: examples/example_write_append.blow5 already closed 398s 09-Mar-24 01:17:01 - [DEBUG]: pathname: examples/example_write_append.blow5 398s 09-Mar-24 01:17:01 - [DEBUG]: total_time_slow5_get_next: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_time_yield_reads: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_single_write_time: 0.026641368865966797 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_multi_write_time: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: FILE: examples/example2.slow5, mode: r 398s 09-Mar-24 01:17:01 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r' 398s 09-Mar-24 01:17:01 - [DEBUG]: Number of read_groups: 4 398s 09-Mar-24 01:17:01 - [DEBUG]: pathname: examples/example2.slow5 398s 09-Mar-24 01:17:01 - [DEBUG]: total_time_slow5_get_next: 0.023125171661376953 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_time_yield_reads: 0.024832487106323242 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_single_write_time: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_multi_write_time: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:01 - [DEBUG]: get_aux_names starting 398s 09-Mar-24 01:17:01 - [DEBUG]: get_aux_names aux_len: 5 398s 09-Mar-24 01:17:01 - [DEBUG]: get_aux_types starting 398s 09-Mar-24 01:17:01 - [DEBUG]: get_aux_types aux_len: 5 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: _record_type_validation running 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: _record_type_validation done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_rec_init() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write assignments... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write assignments done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write processing raw_signal 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write raw_signal done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: channel_number: 281 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string running... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string type: 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: median_before: 231.363533 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: read_number: 4019 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: start_mux: 1 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: start_time: 78470500 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: aux stuff done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() ret: 153015 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_rec_free() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: function complete, returning 0 398s 09-Mar-24 01:17:01 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: _record_type_validation running 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: _record_type_validation done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_rec_init() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write assignments... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write assignments done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write processing raw_signal 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write raw_signal done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: channel_number: 391 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string running... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string type: 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: median_before: 260.557264 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: read_number: 2287 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: start_mux: 2 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: start_time: 36886851 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: aux stuff done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() ret: 76423 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_rec_free() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: function complete, returning 0 398s 09-Mar-24 01:17:01 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: _record_type_validation running 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: _record_type_validation done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_rec_init() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write assignments... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write assignments done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write processing raw_signal 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write raw_signal done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: channel_number: 281 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string running... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string type: 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: median_before: 231.363533 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: read_number: 4019 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: start_mux: 1 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: start_time: 78470500 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: aux stuff done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() ret: 153015 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_rec_free() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: function complete, returning 0 398s 09-Mar-24 01:17:01 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: _record_type_validation running 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: _record_type_validation done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_rec_init() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write assignments... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write assignments done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write processing raw_signal 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write raw_signal done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: channel_number: 391 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string running... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string type: 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: median_before: 260.557264 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: read_number: 2287 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: start_mux: 2 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: start_time: 36886851 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: aux stuff done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() ret: 76423 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_rec_free() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: function complete, returning 0 398s 09-Mar-24 01:17:01 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: _record_type_validation running 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: _record_type_validation done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_rec_init() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write assignments... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write assignments done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write processing raw_signal 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write raw_signal done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: channel_number: 281 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string running... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string type: 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: median_before: 231.363533 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: read_number: 4019 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: start_mux: 1 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: start_time: 78470500 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: aux stuff done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() ret: 153015 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_rec_free() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: function complete, returning 0 398s 09-Mar-24 01:17:01 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: _record_type_validation running 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: _record_type_validation done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_rec_init() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write assignments... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write assignments done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write processing raw_signal 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write raw_signal done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: channel_number: 391 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string running... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string type: 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: median_before: 260.557264 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: read_number: 2287 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: start_mux: 2 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: start_time: 36886851 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: aux stuff done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() ret: 76423 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_rec_free() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: function complete, returning 0 398s 09-Mar-24 01:17:01 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: _record_type_validation running 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: _record_type_validation done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_rec_init() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write assignments... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write assignments done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write processing raw_signal 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write raw_signal done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: channel_number: 281 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string running... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string type: 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: median_before: 231.363533 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: read_number: 4019 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: start_mux: 1 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: start_time: 78470500 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: aux stuff done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() ret: 153049 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_rec_free() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: function complete, returning 0 398s 09-Mar-24 01:17:01 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: _record_type_validation running 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: _record_type_validation done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_rec_init() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write assignments... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write assignments done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write processing raw_signal 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: self.write raw_signal done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: channel_number: 391 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string running... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string type: 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: median_before: 260.557264 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: read_number: 2287 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: start_mux: 2 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: checked_aux: start_time: 36886851 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: aux stuff done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_write() ret: 76457 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: slow5_rec_free() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record: function complete, returning 0 398s 09-Mar-24 01:17:01 - [DEBUG]: slow5_get_next return: -1 398s 09-Mar-24 01:17:01 - [DEBUG]: slow5_get_next reached end of file (EOF)(-1): -1: ['SLOW5_ERR_EOF', 'End Of File reached'] 398s 09-Mar-24 01:17:01 - [DEBUG]: examples/example2.slow5 closed 398s 09-Mar-24 01:17:01 - [DEBUG]: examples/example_write_append_aux.blow5 closed 398s 09-Mar-24 01:17:01 - [DEBUG]: FILE: examples/example2.slow5, mode: r 398s 09-Mar-24 01:17:01 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r' 398s 09-Mar-24 01:17:01 - [DEBUG]: Number of read_groups: 4 398s 09-Mar-24 01:17:01 - [DEBUG]: slow5_get_next_multi return: 3 398s 09-Mar-24 01:17:01 - [DEBUG]: get_aux_names starting 398s 09-Mar-24 01:17:01 - [DEBUG]: get_aux_names aux_len: 5 398s 09-Mar-24 01:17:01 - [DEBUG]: get_aux_types starting 398s 09-Mar-24 01:17:01 - [DEBUG]: get_aux_types aux_len: 5 398s 09-Mar-24 01:17:01 - [DEBUG]: slow5_get_next_multi return: 3 398s 09-Mar-24 01:17:01 - [DEBUG]: slow5_get_next_multi return: 2 398s 09-Mar-24 01:17:01 - [DEBUG]: slow5_get_next_multi has no more batches - batchsize:3 ret:2 398s 09-Mar-24 01:17:01 - [DEBUG]: seq_reads_multi timings: 398s 09-Mar-24 01:17:01 - [DEBUG]: aux_total_time: 0.0005605220794677734 398s 09-Mar-24 01:17:01 - [DEBUG]: primary_total_time: 0.00025153160095214844 398s 09-Mar-24 01:17:01 - [DEBUG]: pA_total_time: 0.0011584758758544922 398s 09-Mar-24 01:17:01 - [DEBUG]: signal_total_time: 0.00023627281188964844 398s 09-Mar-24 01:17:01 - [DEBUG]: examples/example2.slow5 closed 398s 09-Mar-24 01:17:01 - [DEBUG]: FILE: examples/example2.slow5, mode: r 398s 09-Mar-24 01:17:01 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r' 398s 09-Mar-24 01:17:01 - [DEBUG]: Number of read_groups: 4 398s 09-Mar-24 01:17:01 - [DEBUG]: pathname: examples/example2.slow5 398s 09-Mar-24 01:17:01 - [DEBUG]: total_time_slow5_get_next: 0.023033857345581055 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_time_yield_reads: 0.0019943714141845703 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_single_write_time: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_multi_write_time: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: FILE: examples/example2.slow5, mode: r 398s 09-Mar-24 01:17:01 - [DEBUG]: Creating/loading index... 398s 09-Mar-24 01:17:01 - [DEBUG]: Setting up batching... 398s 09-Mar-24 01:17:01 - [DEBUG]: read_list: ['r0', 'r1', 'r2', 'r3', 'r4', 'r5', '0a238451-b9ed-446d-a152-badd074006c4', '0d624d4b-671f-40b8-9798-84f2ccc4d7fc'] 398s 09-Mar-24 01:17:01 - [DEBUG]: batch for loop start 398s 09-Mar-24 01:17:01 - [DEBUG]: Batch: r0,r1,r2 398s 09-Mar-24 01:17:01 - [DEBUG]: Starting rid assignment 398s 09-Mar-24 01:17:01 - [DEBUG]: readID: r0, bin: b'r0' 398s 09-Mar-24 01:17:01 - [DEBUG]: readID: r1, bin: b'r1' 398s 09-Mar-24 01:17:01 - [DEBUG]: readID: r2, bin: b'r2' 398s 09-Mar-24 01:17:01 - [DEBUG]: rid assignment complete 398s 09-Mar-24 01:17:01 - [DEBUG]: slow5_get_batch: num_reads: 3 398s 09-Mar-24 01:17:01 - [DEBUG]: get_read_multi slow5_get_batch ret: 3 398s 09-Mar-24 01:17:01 - [DEBUG]: get_aux_names starting 398s 09-Mar-24 01:17:01 - [DEBUG]: get_aux_names aux_len: 5 398s 09-Mar-24 01:17:01 - [DEBUG]: get_aux_types starting 398s 09-Mar-24 01:17:01 - [DEBUG]: get_aux_types aux_len: 5 398s 09-Mar-24 01:17:01 - [DEBUG]: Batch: r3,r4,r5 398s 09-Mar-24 01:17:01 - [DEBUG]: Starting rid assignment 398s 09-Mar-24 01:17:01 - [DEBUG]: readID: r3, bin: b'r3' 398s 09-Mar-24 01:17:01 - [DEBUG]: readID: r4, bin: b'r4' 398s 09-Mar-24 01:17:01 - [DEBUG]: readID: r5, bin: b'r5' 398s 09-Mar-24 01:17:01 - [DEBUG]: rid assignment complete 398s 09-Mar-24 01:17:01 - [DEBUG]: slow5_get_batch: num_reads: 3 398s 09-Mar-24 01:17:01 - [DEBUG]: get_read_multi slow5_get_batch ret: 3 398s 09-Mar-24 01:17:01 - [DEBUG]: Batch: 0a238451-b9ed-446d-a152-badd074006c4,0d624d4b-671f-40b8-9798-84f2ccc4d7fc 398s 09-Mar-24 01:17:01 - [DEBUG]: Starting rid assignment 398s 09-Mar-24 01:17:01 - [DEBUG]: readID: 0a238451-b9ed-446d-a152-badd074006c4, bin: b'0a238451-b9ed-446d-a152-badd074006c4' 398s 09-Mar-24 01:17:01 - [DEBUG]: readID: 0d624d4b-671f-40b8-9798-84f2ccc4d7fc, bin: b'0d624d4b-671f-40b8-9798-84f2ccc4d7fc' 398s 09-Mar-24 01:17:01 - [DEBUG]: rid assignment complete 398s 09-Mar-24 01:17:01 - [DEBUG]: slow5_get_batch: num_reads: 2 398s 09-Mar-24 01:17:01 - [DEBUG]: get_read_multi slow5_get_batch ret: 2 398s 09-Mar-24 01:17:01 - [DEBUG]: seq_reads_multi timings: 398s 09-Mar-24 01:17:01 - [DEBUG]: examples/example2.slow5 closed 398s 09-Mar-24 01:17:01 - [DEBUG]: FILE: examples/example_write_aux_multi.slow5, mode: w 398s 09-Mar-24 01:17:01 - [DEBUG]: FILE: b'examples/example_write_aux_multi.slow5', mode: b'w' 398s 09-Mar-24 01:17:01 - [DEBUG]: Not writing blow5, skipping compression steps 398s 09-Mar-24 01:17:01 - [DEBUG]: examples/example_write_append_aux.blow5 already closed 398s 09-Mar-24 01:17:01 - [DEBUG]: pathname: examples/example_write_append_aux.blow5 398s 09-Mar-24 01:17:01 - [DEBUG]: total_time_slow5_get_next: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_time_yield_reads: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_single_write_time: 0.02647686004638672 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_multi_write_time: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: FILE: examples/example2.slow5, mode: r 398s 09-Mar-24 01:17:01 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r' 398s 09-Mar-24 01:17:01 - [DEBUG]: Number of read_groups: 4 398s 09-Mar-24 01:17:01 - [DEBUG]: pathname: examples/example2.slow5 398s 09-Mar-24 01:17:01 - [DEBUG]: total_time_slow5_get_next: 0.023151159286499023 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_time_yield_reads: 0.024816036224365234 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_single_write_time: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_multi_write_time: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:01 - [DEBUG]: get_aux_names starting 398s 09-Mar-24 01:17:01 - [DEBUG]: get_aux_names aux_len: 5 398s 09-Mar-24 01:17:01 - [DEBUG]: get_aux_types starting 398s 09-Mar-24 01:17:01 - [DEBUG]: get_aux_types aux_len: 5 398s 09-Mar-24 01:17:01 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:01 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:01 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:01 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:01 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:01 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:01 - [DEBUG]: slow5_get_next return: 0 398s 09-Mar-24 01:17:01 - [DEBUG]: slow5_get_next return: -1 398s 09-Mar-24 01:17:01 - [DEBUG]: slow5_get_next reached end of file (EOF)(-1): -1: ['SLOW5_ERR_EOF', 'End Of File reached'] 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: Setting up batching... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: batch for loop start 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: _record_type_validation running 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux stuff done 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux stuff done 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux stuff done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: _record_type_validation done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: checking header stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: writting header... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: header written 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: slow5_rec_init() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: self.write assignments... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: self.write assignments done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: self.write processing raw_signal 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: self.write raw_signal done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: checked_aux: channel_number: 281 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: slow5_aux_set_string running... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: slow5_aux_set_string type: 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: slow5_aux_set_string running done: ret = 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: checked_aux: median_before: 231.363533 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: checked_aux: read_number: 4019 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: checked_aux: start_mux: 1 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: checked_aux: start_time: 78470500 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: aux stuff done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: slow5_rec_init() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: self.write assignments... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: self.write assignments done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: self.write processing raw_signal 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: self.write raw_signal done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: checked_aux: channel_number: 391 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: slow5_aux_set_string running... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: slow5_aux_set_string type: 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: slow5_aux_set_string running done: ret = 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: checked_aux: median_before: 260.557264 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: checked_aux: read_number: 2287 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: checked_aux: start_mux: 2 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: checked_aux: start_time: 36886851 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: aux stuff done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: slow5_rec_init() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: self.write assignments... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: self.write assignments done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: self.write processing raw_signal 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: self.write raw_signal done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: checked_aux: channel_number: 281 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: slow5_aux_set_string running... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: slow5_aux_set_string type: 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: slow5_aux_set_string running done: ret = 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: checked_aux: median_before: 231.363533 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: checked_aux: read_number: 4019 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: checked_aux: start_mux: 1 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: checked_aux: start_time: 78470500 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: aux stuff done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: slow5_write_batch() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: free() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: free() aux 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: _record_type_validation running 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux stuff done 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux stuff done 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux stuff done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: _record_type_validation done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: slow5_rec_init() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: self.write assignments... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: self.write assignments done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: self.write processing raw_signal 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: self.write raw_signal done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: checked_aux: channel_number: 391 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: slow5_aux_set_string running... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: slow5_aux_set_string type: 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: slow5_aux_set_string running done: ret = 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: checked_aux: median_before: 260.557264 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: checked_aux: read_number: 2287 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: checked_aux: start_mux: 2 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: checked_aux: start_time: 36886851 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: aux stuff done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: slow5_rec_init() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: self.write assignments... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: self.write assignments done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: self.write processing raw_signal 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: self.write raw_signal done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: checked_aux: channel_number: 281 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: slow5_aux_set_string running... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: slow5_aux_set_string type: 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: slow5_aux_set_string running done: ret = 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: checked_aux: median_before: 231.363533 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: checked_aux: read_number: 4019 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: checked_aux: start_mux: 1 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: checked_aux: start_time: 78470500 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: aux stuff done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: slow5_rec_init() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: self.write assignments... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: self.write assignments done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: self.write processing raw_signal 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: self.write raw_signal done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: checked_aux: channel_number: 391 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: slow5_aux_set_string running... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: slow5_aux_set_string type: 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: slow5_aux_set_string running done: ret = 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: checked_aux: median_before: 260.557264 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: checked_aux: read_number: 2287 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: checked_aux: start_mux: 2 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: checked_aux: start_time: 36886851 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: aux stuff done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: slow5_write_batch() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: free() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: free() aux 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: _record_type_validation running 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux stuff done 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: doing aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux passed tests... 398s 09-Mar-24 01:17:01 - [DEBUG]: _record_type_validation: aux stuff done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: _record_type_validation done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: slow5_rec_init() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: self.write assignments... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: self.write assignments done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: self.write processing raw_signal 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: self.write raw_signal done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: checked_aux: channel_number: 281 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: slow5_aux_set_string running... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: slow5_aux_set_string type: 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: slow5_aux_set_string running done: ret = 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: checked_aux: median_before: 231.363533 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: checked_aux: read_number: 4019 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: checked_aux: start_mux: 1 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: checked_aux: start_time: 78470500 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: aux stuff done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: slow5_rec_init() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: self.write assignments... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: self.write.raw_signal malloc... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: self.write.raw_signal malloc done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: self.write assignments done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: self.write processing raw_signal 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: self.write raw_signal done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: aux stuff... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: checked_aux: channel_number: 391 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: slow5_aux_set_string running... 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: slow5_aux_set_string type: 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: slow5_aux_set_string running done: ret = 0 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: checked_aux: median_before: 260.557264 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: checked_aux: read_number: 2287 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: checked_aux: start_mux: 2 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: checked_aux: start_time: 36886851 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: aux stuff done 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: slow5_write_batch() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: free() 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: free() aux 398s 09-Mar-24 01:17:01 - [DEBUG]: write_record_batch: function complete, returning 0 398s 09-Mar-24 01:17:01 - [DEBUG]: examples/example2.slow5 closed 398s 09-Mar-24 01:17:01 - [DEBUG]: examples/example_write_aux_multi.slow5 closed 398s 09-Mar-24 01:17:01 - [DEBUG]: FILE: examples/example2.slow5, mode: r 398s 09-Mar-24 01:17:01 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r' 398s 09-Mar-24 01:17:01 - [DEBUG]: Number of read_groups: 4 398s 09-Mar-24 01:17:01 - [DEBUG]: pathname: examples/example2.slow5 398s 09-Mar-24 01:17:01 - [DEBUG]: total_time_slow5_get_next: 0.022433757781982422 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_time_yield_reads: 0.024070024490356445 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_single_write_time: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_multi_write_time: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: FILE: examples/example2.slow5, mode: r 398s 09-Mar-24 01:17:01 - [DEBUG]: Creating/loading index... 398s 09-Mar-24 01:17:01 - [DEBUG]: examples/example2.slow5 closed 398s |==============================================| 398s | pyslow5 test launch | 398s |==============================================| 398s ['__class__', '__delattr__', '__dir__', '__doc__', '__eq__', '__format__', '__ge__', '__getattribute__', '__getstate__', '__gt__', '__hash__', '__init__', '__init_subclass__', '__le__', '__lt__', '__ne__', '__new__', '__reduce__', '__reduce_ex__', '__repr__', '__setattr__', '__setstate__', '__sizeof__', '__str__', '__subclasshook__', '_aux_header_type_validation', '_convert_to_pA', '_get_batches', '_get_read', '_get_read_aux', '_get_read_multi', '_get_seq_read_aux', '_header_type_validation', '_multi_record_type_validation', '_record_type_validation', 'close', 'get_all_headers', 'get_aux_names', 'get_aux_types', 'get_empty_header', 'get_empty_record', 'get_header_names', 'get_header_value', 'get_read', 'get_read_ids', 'get_read_list', 'get_read_list_multi', 'seq_reads', 'seq_reads_multi', 'write_header', 'write_record', 'write_record_batch'] 398s slow5 file opened and object created in: 0.0003 seconds 398s ============================================== 398s get_read check, r1 398s get_read in: 0.0048 seconds 398s read_id: r1 398s read_group: 0 398s digitisation: 8192.0 398s offset: 23.0 398s range: 1467.61 398s sampling_rate: 4000.0 398s len_raw_signal: 59676 398s signal: [1039 588 588 593 586 574 570 585 588 586] 398s pylen of signal: 59676 398s AUX FIELDS: 398s read_number: None 398s start_mux: None 398s blah: None 398s ============================================== 398s get_read check, r4, converte to pA 398s get_read in: 0.0038 seconds 398s read_id: r4 398s read_group: 0 398s digitisation: 8192.0 398s offset: 23.0 398s range: 1467.61 398s sampling_rate: 4000.0 398s len_raw_signal: 59670 398s signal: [190.25902 108.92418 109.46163 109.10333 107.67012 108.38673 398s 108.745026 109.10333 111.074 108.38673 ] 398s pylen of signal: 59670 398s signal value type: 398s ============================================== 398s seq_reads check, all reads 398s seq_reads readIDs: 398s type check reads: 398s r1 398s r2 398s r3 398s r4 398s r5 398s seq_reads in: 0.0159 seconds 398s ============================================== 398s Yield check, selected reads 398s get_read_list in: 0.0 seconds 398s yielded readIDs: 398s r1 r1 398s r3 r3 398s null_read read not found, None returned 398s r5 r5 398s r2 r2 398s r1 r1 398s ============================================== 398s Get headder names 398s header names: 398s ['asic_id', 'asic_id_eeprom', 'asic_temp', 'auto_update', 'auto_update_source', 'bream_core_version', 'bream_is_standard', 'bream_map_version', 'bream_ont_version', 'bream_prod_version', 'bream_rnd_version', 'device_id', 'exp_script_name', 'exp_script_purpose', 'exp_start_time', 'experiment_kit', 'experiment_type', 'file_version', 'filename', 'flow_cell_id', 'heatsink_temp', 'hostname', 'installation_type', 'local_firmware_file', 'operating_system', 'protocol_run_id', 'protocols_version', 'run_id', 'sample_frequency', 'usb_config', 'user_filename_input', 'version'] 398s ============================================== 398s get_all_headers 398s {'asic_id': '3574887596', 'asic_id_eeprom': '0', 'asic_temp': '29.2145729', 'auto_update': '1', 'auto_update_source': 'https://mirror.oxfordnanoportal.com/software/MinKNOW/', 'bream_core_version': '1.1.20.1', 'bream_is_standard': '1', 'bream_map_version': '1.1.20.1', 'bream_ont_version': '1.1.20.1', 'bream_prod_version': '1.1.20.1', 'bream_rnd_version': '0.1.1', 'device_id': 'MN16450', 'exp_script_name': 'python/recipes/nc/NC_48Hr_Sequencing_Run_FLO-MIN106_SQK-LSK108.py', 'exp_script_purpose': 'sequencing_run', 'exp_start_time': '1479433093', 'experiment_kit': 'genomic_dna', 'experiment_type': 'customer_qc', 'file_version': '1', 'filename': 'deamernanopore_20161117_fnfab43577_mn16450_sequencing_run_ma_821_r9_4_na12878_11_17_16_88738', 'flow_cell_id': 'FAB43577', 'heatsink_temp': '33.9921875', 'hostname': 'DEAMERNANOPORE', 'installation_type': 'map', 'local_firmware_file': '0', 'operating_system': 'Windows 6.2', 'protocol_run_id': 'a4429838-103c-497f-a824-7dffa72cfd81', 'protocols_version': '1.1.20', 'run_id': 'd6e473a6d513ec6bfc150c60fd4556d72f0e6d18', 'sample_frequency': '4000', 'usb_config': '1.0.11_ONT#MinION_fpga_1.0.1#ctrl#Auto', 'user_filename_input': 'ma_821_r9.4_na12878_11_17_16', 'version': '1.1.20'} 398s ============================================== 398s Get headder attributes 398s flow_cell_id: FAB43577 398s exp_start_time: 1479433093 398s heatsink_temp: 33.9921875 398s asic_id: 3574887596 398s asic_id_eeprom: 0 398s asic_temp: 29.2145729 398s auto_update: 1 398s auto_update_source: https://mirror.oxfordnanoportal.com/software/MinKNOW/ 398s bream_core_version: 1.1.20.1 398s bream_is_standard: 1 398s bream_map_version: 1.1.20.1 398s bream_ont_version: 1.1.20.1 398s bream_prod_version: 1.1.20.1 398s bream_rnd_version: 0.1.1 398s device_id: MN16450 398s exp_script_name: python/recipes/nc/NC_48Hr_Sequencing_Run_FLO-MIN106_SQK-LSK108.py 398s exp_script_purpose: sequencing_run 398s exp_start_time: 1479433093 398s experiment_kit: genomic_dna 398s experiment_type: customer_qc 398s file_version: 1 398s filename: deamernanopore_20161117_fnfab43577_mn16450_sequencing_run_ma_821_r9_4_na12878_11_17_16_88738 398s flow_cell_id: FAB43577 398s heatsink_temp: 33.9921875 398s hostname: DEAMERNANOPORE 398s installation_type: map 398s local_firmware_file: 0 398s operating_system: Windows 6.2 398s protocol_run_id: a4429838-103c-497f-a824-7dffa72cfd81 398s protocols_version: 1.1.20 398s run_id: d6e473a6d513ec6bfc150c60fd4556d72f0e6d18 398s sample_frequency: 4000 398s usb_config: 1.0.11_ONT#MinION_fpga_1.0.1#ctrl#Auto 398s user_filename_input: ma_821_r9.4_na12878_11_17_16 398s version: 1.1.20 398s ============================================== 398s get_read check, 0d624d4b-671f-40b8-9798-84f2ccc4d7fc 398s read_id: 0d624d4b-671f-40b8-9798-84f2ccc4d7fc 398s read_group: 3 398s digitisation: 8192.0 398s offset: 6.0 398s range: 1444.86 398s sampling_rate: 4000.0 398s len_raw_signal: 38164 398s signal: [1462 1075 795 801 797 788 817 791 801 802] 398s pylen of signal: 38164 398s AUX FIELDS: 398s read_number: 2287 398s start_mux: 2 398s blah: None 398s AUX FIELDS: 398s blah: None 398s AUX FIELDS: 398s read_number: 2287 398s ============================================== 398s Get aux names 398s aux names: 398s ['channel_number', 'median_before', 'read_number', 'start_mux', 'start_time'] 398s ============================================== 398s Get aux types 398s aux types: 398s [22, 9, 2, 4, 7] 398s ============================================== 398s AUX FIELDS: 398s channel_number: 391 398s median_before: 260.557264 398s read_number: 2287 398s start_mux: 2 398s start_time: 36886851 398s ============================================== 398s seq_reads with aux: 398s type check reads: 398s r0 398s read_number 4019 398s r1 398s read_number 2287 398s r2 398s read_number 4019 398s r3 398s read_number 2287 398s r4 398s read_number 4019 398s r5 398s read_number 2287 398s 0a238451-b9ed-446d-a152-badd074006c4 398s read_number 4019 398s 0d624d4b-671f-40b8-9798-84f2ccc4d7fc 398s read_number 2287 398s ============================================== 398s write reads no aux 398s ret: write_header(): 0 398s ret: write_record(): 0 398s ret: write_record(): 0 398s ret: write_record(): 0 398s ret: write_record(): 0 398s ret: write_record(): 0 398s ret: write_record(): 0 398s ret: write_record(): 0 398s ret: write_record(): 0 398s ============================================== 398s append reads no aux 398s ret: write_header(): 0 398s ret: write_record(): 0 398s ret: write_record(): 0 398s ret: write_record(): 0 398s ret: write_record(): 0 398s ret: write_record(): 0 398s ret: write_record(): 0 398s ret: write_record(): 0 398s ret: write_record(): 0 398s get_all_headers 398s {'asic_id': 'test_0', 'asic_id_eeprom': 'test_1', 'asic_temp': 'test_2', 'asic_version': 'test_3', 'auto_update': 'test_4', 'auto_update_source': 'test_5', 'barcoding_enabled': 'test_6', 'bream_is_standard': 'test_7', 'configuration_version': 'test_8', 'device_id': 'test_9', 'device_type': 'test_10', 'distribution_status': 'test_11', 'distribution_version': 'test_12', 'exp_script_name': 'test_13', 'exp_script_purpose': 'test_14', 'exp_start_time': 'test_15', 'experiment_duration_set': 'test_16', 'flow_cell_id': 'test_17', 'flow_cell_product_code': 'test_18', 'guppy_version': 'test_19', 'heatsink_temp': 'test_20', 'hostname': 'test_21', 'hublett_board_id': 'test_36', 'installation_type': 'test_22', 'local_basecalling': 'test_23', 'operating_system': 'test_24', 'package': 'test_25', 'protocol_group_id': 'test_26', 'protocol_run_id': 'test_27', 'protocol_start_time': 'test_28', 'protocols_version': 'test_29', 'run_id': 'test_30', 'sample_frequency': 'test_31', 'sample_id': 'test_32', 'satellite_firmware_version': 'test_37', 'sequencing_kit': 'test_33', 'usb_config': 'test_34', 'version': 'test_35'} 398s ret: write_record(): 0 398s ret: write_record(): 0 398s ret: write_record(): 0 398s ret: write_record(): 0 398s ret: write_record(): 0 398s ret: write_record(): 0 398s ret: write_record(): 0 398s ret: write_record(): 0 398s ============================================== 398s write reads with aux 398s ret: write_header(): 0 398s ret: write_header(): 0 398s ret: write_record(): 0 398s ret: write_record(): 0 398s ret: write_record(): 0 398s ret: write_record(): 0 398s ret: write_record(): 0 398s ret: write_record(): 0 398s ret: write_record(): 0 398s ret: write_record(): 0 398s ============================================== 398s append reads with aux 398s ret: write_header(): 0 398s ret: write_header(): 0 398s ret: write_record(): 0 398s ret: write_record(): 0 398s ret: write_record(): 0 398s ret: write_record(): 0 398s ret: write_record(): 0 398s ret: write_record(): 0 398s ret: write_record(): 0 398s ret: write_record(): 0 398s ret: write_record(): 0 398s ret: write_record(): 0 398s ret: write_record(): 0 398s ret: write_record(): 0 398s ret: write_record(): 0 398s ret: write_record(): 0 398s ret: write_record(): 0 398s ret: write_record(): 0 398s ============================================== 398s seq_reads_multi with aux: 398s type check reads: 398s r0 398s read_number 4019 398s r1 398s read_number 2287 398s r2 398s read_number 4019 398s r3 398s read_number 2287 398s r4 398s read_number 4019 398s r5 398s read_number 2287 398s 0a238451-b9ed-446d-a152-badd074006c4 398s read_number 4019 398s 0d624d4b-671f-40b8-9798-84f2ccc4d7fc 398s read_number 2287 398s ============================================== 398s get_reads_multi with aux: 398s type check reads: 398s r0 398s read_number 4019 398s r1 398s read_number 2287 398s r2 398s read_number 4019 398s r3 398s read_number 2287 398s r4 398s read_number 4019 398s r5 398s read_number 2287 398s 0a238451-b9ed-446d-a152-badd074006c4 398s read_number 4019 398s 0d624d4b-671f-40b8-9798-84f2ccc4d7fc 398s read_number 2287 398s ============================================== 398s write reads with aux multi 398s ret: write_header(): 0 398s ret: write_header(): 0 398s {'r0': {'read_id': 'r0', 'read_group': 0, 'digitisation': 8192.0, 'offset': 2.0, 'range': 1444.86, 'sampling_rate': 4000.0, 'len_raw_signal': 76460, 'signal': array([1299, 771, 556, ..., 554, 560, 566], dtype=int16)}, 'r1': {'read_id': 'r1', 'read_group': 0, 'digitisation': 8192.0, 'offset': 6.0, 'range': 1444.86, 'sampling_rate': 4000.0, 'len_raw_signal': 38164, 'signal': array([1462, 1075, 795, ..., 696, 706, 702], dtype=int16)}, 'r2': {'read_id': 'r2', 'read_group': 1, 'digitisation': 8192.0, 'offset': 2.0, 'range': 1444.86, 'sampling_rate': 4000.0, 'len_raw_signal': 76460, 'signal': array([1299, 771, 556, ..., 554, 560, 566], dtype=int16)}, 'r3': {'read_id': 'r3', 'read_group': 1, 'digitisation': 8192.0, 'offset': 6.0, 'range': 1444.86, 'sampling_rate': 4000.0, 'len_raw_signal': 38164, 'signal': array([1462, 1075, 795, ..., 696, 706, 702], dtype=int16)}, 'r4': {'read_id': 'r4', 'read_group': 2, 'digitisation': 8192.0, 'offset': 2.0, 'range': 1444.86, 'sampling_rate': 4000.0, 'len_raw_signal': 76460, 'signal': array([1299, 771, 556, ..., 554, 560, 566], dtype=int16)}, 'r5': {'read_id': 'r5', 'read_group': 2, 'digitisation': 8192.0, 'offset': 6.0, 'range': 1444.86, 'sampling_rate': 4000.0, 'len_raw_signal': 38164, 'signal': array([1462, 1075, 795, ..., 696, 706, 702], dtype=int16)}, '0a238451-b9ed-446d-a152-badd074006c4': {'read_id': '0a238451-b9ed-446d-a152-badd074006c4', 'read_group': 3, 'digitisation': 8192.0, 'offset': 2.0, 'range': 1444.86, 'sampling_rate': 4000.0, 'len_raw_signal': 76460, 'signal': array([1299, 771, 556, ..., 554, 560, 566], dtype=int16)}, '0d624d4b-671f-40b8-9798-84f2ccc4d7fc': {'read_id': '0d624d4b-671f-40b8-9798-84f2ccc4d7fc', 'read_group': 3, 'digitisation': 8192.0, 'offset': 6.0, 'range': 1444.86, 'sampling_rate': 4000.0, 'len_raw_signal': 38164, 'signal': array([1462, 1075, 795, ..., 696, 706, 702], dtype=int16)}} 398s {'r0': {'channel_number': '281', 'median_before': 231.363533, 'read_number': 4019, 'start_mux': 1, 'start_time': 78470500}, 'r1': {'channel_number': '391', 'median_before': 260.557264, 'read_number': 2287, 'start_mux': 2, 'start_time': 36886851}, 'r2': {'channel_number': '281', 'median_before': 231.363533, 'read_number': 4019, 'start_mux': 1, 'start_time': 78470500}, 'r3': {'channel_number': '391', 'median_before': 260.557264, 'read_number': 2287, 'start_mux': 2, 'start_time': 36886851}, 'r4': {'channel_number': '281', 'median_before': 231.363533, 'read_number': 4019, 'start_mux': 1, 'start_time': 78470500}, 'r5': {'channel_number': '391', 'median_before': 260.557264, 'read_number': 2287, 'start_mux': 2, 'start_time': 36886851}, '0a238451-b9ed-446d-a152-badd074006c4': {'channel_number': '281', 'median_before': 231.363533, 'read_number': 4019, 'start_mux': 1, 'start_time': 78470500}, '0d624d4b-671f-40b8-9798-84f2ccc4d7fc': {'channel_number': '391', 'median_before': 260.557264, 'read_number': 2287, 'start_mux': 2, 'start_time': 36886851}} 398s ret: write_record(): 0 398s ============================================== 398s get all readIDs from index 398s ['r0', 'r1', 'r2', 'r3', 'r4', 'r5', '0a238451-b9ed-446d-a152-badd074006c4', '0d624d4b-671f-40b8-9798-84f2ccc4d7fc'] 398s number of reads: 8 398s ============================================== 398s done 398s 09-Mar-24 01:17:01 - [DEBUG]: pathname: examples/example.slow5 398s 09-Mar-24 01:17:01 - [DEBUG]: total_time_slow5_get_next: 0.015059471130371094 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_time_yield_reads: 0.015655517578125 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_single_write_time: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_multi_write_time: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: pathname: examples/example2.slow5 398s 09-Mar-24 01:17:01 - [DEBUG]: total_time_slow5_get_next: 0.02213573455810547 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_time_yield_reads: 0.024705171585083008 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_single_write_time: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_multi_write_time: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: examples/example_write_aux_multi.slow5 already closed 398s 09-Mar-24 01:17:01 - [DEBUG]: pathname: examples/example_write_aux_multi.slow5 398s 09-Mar-24 01:17:01 - [DEBUG]: total_time_slow5_get_next: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_time_yield_reads: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_single_write_time: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_multi_write_signal_time: 0.03136706352233887 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_multi_write_time: 0.08972620964050293 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: pathname: examples/example2.slow5 398s 09-Mar-24 01:17:01 - [DEBUG]: total_time_slow5_get_next: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_time_yield_reads: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_single_write_time: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_multi_write_time: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: examples/example_write_append_aux.blow5 already closed 398s 09-Mar-24 01:17:01 - [DEBUG]: pathname: examples/example_write_append_aux.blow5 398s 09-Mar-24 01:17:01 - [DEBUG]: total_time_slow5_get_next: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_time_yield_reads: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_single_write_time: 0.02738332748413086 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_multi_write_time: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: pathname: examples/example2.slow5 398s 09-Mar-24 01:17:01 - [DEBUG]: total_time_slow5_get_next: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_time_yield_reads: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_single_write_time: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 398s 09-Mar-24 01:17:01 - [DEBUG]: total_multi_write_time: 0.0 seconds 399s autopkgtest [01:17:02]: test run-pybinding-test: -----------------------] 399s run-pybinding-test PASS 399s autopkgtest [01:17:02]: test run-pybinding-test: - - - - - - - - - - results - - - - - - - - - - 399s autopkgtest [01:17:02]: test run-pkg-test: preparing testbed 640s autopkgtest [01:21:03]: @@@@@@@@@@@@@@@@@@@@ test bed setup 640s Get:1 http://ftpmaster.internal/ubuntu noble-proposed InRelease [117 kB] 640s Get:2 http://ftpmaster.internal/ubuntu noble-proposed/universe Sources [2547 kB] 641s Get:3 http://ftpmaster.internal/ubuntu noble-proposed/main Sources [437 kB] 641s Get:4 http://ftpmaster.internal/ubuntu noble-proposed/restricted Sources [3976 B] 641s Get:5 http://ftpmaster.internal/ubuntu noble-proposed/multiverse Sources [35.7 kB] 641s Get:6 http://ftpmaster.internal/ubuntu noble-proposed/main ppc64el Packages [578 kB] 641s Get:7 http://ftpmaster.internal/ubuntu noble-proposed/main ppc64el c-n-f Metadata [3116 B] 641s Get:8 http://ftpmaster.internal/ubuntu noble-proposed/restricted ppc64el Packages [1372 B] 641s Get:9 http://ftpmaster.internal/ubuntu noble-proposed/restricted ppc64el c-n-f Metadata [116 B] 641s Get:10 http://ftpmaster.internal/ubuntu noble-proposed/universe ppc64el Packages [2754 kB] 641s Get:11 http://ftpmaster.internal/ubuntu noble-proposed/universe ppc64el c-n-f Metadata [8652 B] 641s Get:12 http://ftpmaster.internal/ubuntu noble-proposed/multiverse ppc64el Packages [37.0 kB] 641s Get:13 http://ftpmaster.internal/ubuntu noble-proposed/multiverse ppc64el c-n-f Metadata [116 B] 643s Fetched 6522 kB in 2s (3460 kB/s) 643s Reading package lists... 648s Reading package lists... 648s Building dependency tree... 648s Reading state information... 648s Calculating upgrade... 648s The following packages will be upgraded: 648s zlib1g 648s 1 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 648s Need to get 72.8 kB of archives. 648s After this operation, 0 B of additional disk space will be used. 648s Get:1 http://ftpmaster.internal/ubuntu noble-proposed/main ppc64el zlib1g ppc64el 1:1.3.dfsg-3.1ubuntu1 [72.8 kB] 649s Fetched 72.8 kB in 0s (268 kB/s) 649s (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 ... 70107 files and directories currently installed.) 649s Preparing to unpack .../zlib1g_1%3a1.3.dfsg-3.1ubuntu1_ppc64el.deb ... 649s Unpacking zlib1g:ppc64el (1:1.3.dfsg-3.1ubuntu1) over (1:1.3.dfsg-3ubuntu1) ... 649s Setting up zlib1g:ppc64el (1:1.3.dfsg-3.1ubuntu1) ... 649s Processing triggers for libc-bin (2.39-0ubuntu2) ... 649s W: Target Packages (main/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 649s W: Target Packages (main/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 649s W: Target CNF (main/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 649s W: Target CNF (main/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 649s W: Target Packages (universe/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 649s W: Target Packages (universe/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 649s W: Target CNF (universe/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 649s W: Target CNF (universe/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 649s W: Target Packages (restricted/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 649s W: Target Packages (restricted/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 649s W: Target CNF (restricted/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 649s W: Target CNF (restricted/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 649s W: Target Packages (multiverse/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 649s W: Target Packages (multiverse/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 649s W: Target CNF (multiverse/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 649s W: Target CNF (multiverse/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 649s W: Target Packages (main/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 649s W: Target Packages (main/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 649s W: Target CNF (main/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 649s W: Target CNF (main/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 649s W: Target Packages (universe/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 649s W: Target Packages (universe/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 649s W: Target CNF (universe/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 649s W: Target CNF (universe/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 649s W: Target Packages (restricted/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 649s W: Target Packages (restricted/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 649s W: Target CNF (restricted/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 649s W: Target CNF (restricted/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 649s W: Target Packages (multiverse/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 649s W: Target Packages (multiverse/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 649s W: Target CNF (multiverse/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 649s W: Target CNF (multiverse/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 649s W: Target Packages (main/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 649s W: Target Packages (main/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 649s W: Target CNF (main/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 649s W: Target CNF (main/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 649s W: Target Packages (universe/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 649s W: Target Packages (universe/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 649s W: Target CNF (universe/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 649s W: Target CNF (universe/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 649s W: Target Packages (restricted/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 649s W: Target Packages (restricted/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 649s W: Target CNF (restricted/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 649s W: Target CNF (restricted/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 649s W: Target Packages (multiverse/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 649s W: Target Packages (multiverse/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 649s W: Target CNF (multiverse/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 649s W: Target CNF (multiverse/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 649s Reading package lists... 650s Building dependency tree... 650s Reading state information... 650s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 650s sh: Attempting to set up Debian/Ubuntu apt sources automatically 650s sh: Distribution appears to be Ubuntu 654s Reading package lists... 654s Building dependency tree... 654s Reading state information... 654s eatmydata is already the newest version (131-1). 654s dbus is already the newest version (1.14.10-4ubuntu1). 654s dbus set to manually installed. 654s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 654s W: Target Packages (main/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 654s W: Target Packages (main/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 654s W: Target CNF (main/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 654s W: Target CNF (main/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 654s W: Target Packages (universe/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 654s W: Target Packages (universe/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 654s W: Target CNF (universe/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 654s W: Target CNF (universe/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 654s W: Target Packages (restricted/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 654s W: Target Packages (restricted/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 654s W: Target CNF (restricted/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 654s W: Target CNF (restricted/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 654s W: Target Packages (multiverse/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 654s W: Target Packages (multiverse/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 654s W: Target CNF (multiverse/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 654s W: Target CNF (multiverse/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 654s W: Target Packages (main/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 654s W: Target Packages (main/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 654s W: Target CNF (main/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 654s W: Target CNF (main/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 654s W: Target Packages (universe/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 654s W: Target Packages (universe/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 654s W: Target CNF (universe/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 654s W: Target CNF (universe/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 654s W: Target Packages (restricted/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 654s W: Target Packages (restricted/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 654s W: Target CNF (restricted/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 654s W: Target CNF (restricted/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 654s W: Target Packages (multiverse/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 654s W: Target Packages (multiverse/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 654s W: Target CNF (multiverse/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 654s W: Target CNF (multiverse/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 654s W: Target Packages (main/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 654s W: Target Packages (main/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 654s W: Target CNF (main/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 654s W: Target CNF (main/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 654s W: Target Packages (universe/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 654s W: Target Packages (universe/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 654s W: Target CNF (universe/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 654s W: Target CNF (universe/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 654s W: Target Packages (restricted/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 654s W: Target Packages (restricted/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 654s W: Target CNF (restricted/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 654s W: Target CNF (restricted/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 654s W: Target Packages (multiverse/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 654s W: Target Packages (multiverse/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 654s W: Target CNF (multiverse/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 654s W: Target CNF (multiverse/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 654s Reading package lists... 654s Building dependency tree... 654s Reading state information... 655s rng-tools-debian is already the newest version (2.4). 655s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 655s Reading package lists... 655s Building dependency tree... 655s Reading state information... 655s haveged is already the newest version (1.9.14-1ubuntu1). 655s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 655s Reading package lists... 655s Building dependency tree... 655s Reading state information... 655s The following packages will be REMOVED: 655s cloud-init* python3-configobj* python3-debconf* 656s 0 upgraded, 0 newly installed, 3 to remove and 0 not upgraded. 656s After this operation, 3248 kB disk space will be freed. 656s (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 ... 70107 files and directories currently installed.) 656s Removing cloud-init (24.1-0ubuntu1) ... 656s Removing python3-configobj (5.0.8-3) ... 656s Removing python3-debconf (1.5.86) ... 656s Processing triggers for man-db (2.12.0-3) ... 657s (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 ... 69718 files and directories currently installed.) 657s Purging configuration files for cloud-init (24.1-0ubuntu1) ... 657s dpkg: warning: while removing cloud-init, directory '/etc/cloud/cloud.cfg.d' not empty so not removed 657s Processing triggers for rsyslog (8.2312.0-3ubuntu3) ... 658s Reading package lists... 658s Building dependency tree... 658s Reading state information... 658s linux-generic is already the newest version (6.8.0-11.11+1). 658s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 659s Get:1 http://ftpmaster.internal/ubuntu noble InRelease [255 kB] 659s Hit:2 http://ftpmaster.internal/ubuntu noble-updates InRelease 659s Hit:3 http://ftpmaster.internal/ubuntu noble-security InRelease 659s Get:4 http://ftpmaster.internal/ubuntu noble-proposed InRelease [117 kB] 659s Hit:5 http://ftpmaster.internal/ubuntu noble-backports InRelease 659s Get:6 http://ftpmaster.internal/ubuntu noble/main Sources [1390 kB] 659s Get:7 http://ftpmaster.internal/ubuntu noble/universe Sources [19.8 MB] 660s Get:8 http://ftpmaster.internal/ubuntu noble/main ppc64el Packages [1380 kB] 660s Get:9 http://ftpmaster.internal/ubuntu noble/universe ppc64el Packages [14.9 MB] 661s Get:10 http://ftpmaster.internal/ubuntu noble-proposed/universe Sources [2584 kB] 661s Get:11 http://ftpmaster.internal/ubuntu noble-proposed/main Sources [431 kB] 661s Get:12 http://ftpmaster.internal/ubuntu noble-proposed/main ppc64el Packages [574 kB] 661s Get:13 http://ftpmaster.internal/ubuntu noble-proposed/universe ppc64el Packages [2752 kB] 667s Fetched 44.3 MB in 8s (5516 kB/s) 670s Reading package lists... 670s W: Target Packages (main/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target Packages (main/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target CNF (main/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target CNF (main/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target Packages (universe/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target Packages (universe/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target CNF (universe/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target CNF (universe/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target Packages (restricted/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target Packages (restricted/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target CNF (restricted/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target CNF (restricted/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target Packages (multiverse/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target Packages (multiverse/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target CNF (multiverse/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target CNF (multiverse/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target Packages (main/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target Packages (main/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target CNF (main/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target CNF (main/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target Packages (universe/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target Packages (universe/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target CNF (universe/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target CNF (universe/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target Packages (restricted/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target Packages (restricted/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target CNF (restricted/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target CNF (restricted/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target Packages (multiverse/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target Packages (multiverse/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target CNF (multiverse/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target CNF (multiverse/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target Packages (main/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 670s W: Target Packages (main/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 670s W: Target CNF (main/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 670s W: Target CNF (main/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 670s W: Target Packages (universe/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 670s W: Target Packages (universe/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 670s W: Target CNF (universe/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 670s W: Target CNF (universe/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 670s W: Target Packages (restricted/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 670s W: Target Packages (restricted/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 670s W: Target CNF (restricted/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 670s W: Target CNF (restricted/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 670s W: Target Packages (multiverse/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 670s W: Target Packages (multiverse/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 670s W: Target CNF (multiverse/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 670s W: Target CNF (multiverse/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 670s W: Target Packages (main/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target Packages (main/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target CNF (main/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target CNF (main/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target Packages (universe/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target Packages (universe/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target CNF (universe/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target CNF (universe/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target Packages (restricted/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target Packages (restricted/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target CNF (restricted/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target CNF (restricted/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target Packages (multiverse/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target Packages (multiverse/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target CNF (multiverse/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target CNF (multiverse/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:1 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target Packages (main/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target Packages (main/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target CNF (main/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target CNF (main/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target Packages (universe/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target Packages (universe/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target CNF (universe/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target CNF (universe/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target Packages (restricted/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target Packages (restricted/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target CNF (restricted/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target CNF (restricted/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target Packages (multiverse/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target Packages (multiverse/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target CNF (multiverse/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target CNF (multiverse/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:2 and /etc/apt/sources.list.d/ubuntu.sources:1 670s W: Target Packages (main/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 670s W: Target Packages (main/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 670s W: Target CNF (main/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 670s W: Target CNF (main/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 670s W: Target Packages (universe/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 670s W: Target Packages (universe/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 670s W: Target CNF (universe/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 670s W: Target CNF (universe/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 670s W: Target Packages (restricted/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 670s W: Target Packages (restricted/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 670s W: Target CNF (restricted/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 670s W: Target CNF (restricted/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 670s W: Target Packages (multiverse/binary-ppc64el/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 670s W: Target Packages (multiverse/binary-all/Packages) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 670s W: Target CNF (multiverse/cnf/Commands-ppc64el) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 670s W: Target CNF (multiverse/cnf/Commands-all) is configured multiple times in /etc/apt/sources.list:3 and /etc/apt/sources.list.d/ubuntu.sources:2 670s Reading package lists... 670s Building dependency tree... 670s Reading state information... 670s Calculating upgrade... 670s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 671s Reading package lists... 671s Building dependency tree... 671s Reading state information... 671s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 671s autopkgtest [01:21:34]: rebooting testbed after setup commands that affected boot 842s autopkgtest-virt-ssh: WARNING: ssh connection failed. Retrying in 3 seconds... 848s autopkgtest [01:24:31]: testbed dpkg architecture: ppc64el 858s Reading package lists... 858s Building dependency tree... 858s Reading state information... 858s Correcting dependencies...Starting pkgProblemResolver with broken count: 0 858s Starting 2 pkgProblemResolver with broken count: 0 858s Done 858s Done 858s Starting pkgProblemResolver with broken count: 0 858s Starting 2 pkgProblemResolver with broken count: 0 858s Done 859s The following additional packages will be installed: 859s build-essential cpp cpp-13 cpp-13-powerpc64le-linux-gnu 859s cpp-powerpc64le-linux-gnu g++ g++-13 g++-13-powerpc64le-linux-gnu 859s g++-powerpc64le-linux-gnu gcc gcc-13 gcc-13-powerpc64le-linux-gnu 859s gcc-powerpc64le-linux-gnu libasan8 libatomic1 libblas3 libc-dev-bin 859s libc6-dev libcc1-0 libcrypt-dev libgcc-13-dev libgfortran5 libgomp1 libisl23 859s libitm1 liblapack3 liblsan0 libmpc3 libnsl-dev libquadmath0 libslow5-0 859s libslow5-dev libstdc++-13-dev libstreamvbyte-dev libstreamvbyte0 859s libtirpc-dev libtsan2 libubsan1 linux-libc-dev python3-numpy python3-slow5 859s rpcsvc-proto zlib1g-dev 859s Suggested packages: 859s cpp-doc gcc-13-locales cpp-13-doc gcc-13-doc gcc-multilib manpages-dev 859s autoconf automake libtool flex bison gdb gcc-doc gdb-powerpc64le-linux-gnu 859s glibc-doc libstdc++-13-doc gfortran python3-dev python3-pytest 859s Recommended packages: 859s manpages manpages-dev libc-devtools 859s The following NEW packages will be installed: 859s build-essential cpp cpp-13 cpp-13-powerpc64le-linux-gnu 859s cpp-powerpc64le-linux-gnu g++ g++-13 g++-13-powerpc64le-linux-gnu 859s g++-powerpc64le-linux-gnu gcc gcc-13 gcc-13-powerpc64le-linux-gnu 859s gcc-powerpc64le-linux-gnu libasan8 libatomic1 libblas3 libc-dev-bin 859s libc6-dev libcc1-0 libcrypt-dev libgcc-13-dev libgfortran5 libgomp1 libisl23 859s libitm1 liblapack3 liblsan0 libmpc3 libnsl-dev libquadmath0 libslow5-0 859s libslow5-dev libstdc++-13-dev libstreamvbyte-dev libstreamvbyte0 859s libtirpc-dev libtsan2 libubsan1 linux-libc-dev python3-numpy python3-slow5 859s rpcsvc-proto zlib1g-dev 859s 0 upgraded, 43 newly installed, 0 to remove and 0 not upgraded. 859s 1 not fully installed or removed. 859s Need to get 72.8 MB of archives. 859s After this operation, 297 MB of additional disk space will be used. 859s Get:1 http://ftpmaster.internal/ubuntu noble/universe ppc64el libslow5-0 ppc64el 0.7.0+dfsg-2ubuntu4 [69.2 kB] 859s Get:2 http://ftpmaster.internal/ubuntu noble/universe ppc64el libslow5-dev ppc64el 0.7.0+dfsg-2ubuntu4 [102 kB] 859s Get:3 http://ftpmaster.internal/ubuntu noble/universe ppc64el libstreamvbyte0 ppc64el 0.4.1-4ubuntu1 [6400 B] 859s Get:4 http://ftpmaster.internal/ubuntu noble/main ppc64el libblas3 ppc64el 3.12.0-3 [227 kB] 859s Get:5 http://ftpmaster.internal/ubuntu noble/main ppc64el libgfortran5 ppc64el 14-20240303-1ubuntu1 [574 kB] 859s Get:6 http://ftpmaster.internal/ubuntu noble/main ppc64el liblapack3 ppc64el 3.12.0-3 [2804 kB] 859s Get:7 http://ftpmaster.internal/ubuntu noble/main ppc64el python3-numpy ppc64el 1:1.24.2-2 [5581 kB] 860s Get:8 http://ftpmaster.internal/ubuntu noble/universe ppc64el python3-slow5 ppc64el 0.7.0+dfsg-2ubuntu4 [645 kB] 860s Get:9 http://ftpmaster.internal/ubuntu noble/main ppc64el libc-dev-bin ppc64el 2.39-0ubuntu2 [21.3 kB] 860s Get:10 http://ftpmaster.internal/ubuntu noble/main ppc64el linux-libc-dev ppc64el 6.8.0-11.11 [1585 kB] 860s Get:11 http://ftpmaster.internal/ubuntu noble/main ppc64el libcrypt-dev ppc64el 1:4.4.36-4 [167 kB] 860s Get:12 http://ftpmaster.internal/ubuntu noble/main ppc64el libtirpc-dev ppc64el 1.3.4+ds-1build1 [262 kB] 860s Get:13 http://ftpmaster.internal/ubuntu noble/main ppc64el libnsl-dev ppc64el 1.3.0-3 [79.2 kB] 860s Get:14 http://ftpmaster.internal/ubuntu noble/main ppc64el rpcsvc-proto ppc64el 1.4.2-0ubuntu6 [82.3 kB] 860s Get:15 http://ftpmaster.internal/ubuntu noble/main ppc64el libc6-dev ppc64el 2.39-0ubuntu2 [2102 kB] 860s Get:16 http://ftpmaster.internal/ubuntu noble/main ppc64el libisl23 ppc64el 0.26-3 [864 kB] 860s Get:17 http://ftpmaster.internal/ubuntu noble/main ppc64el libmpc3 ppc64el 1.3.1-1 [61.2 kB] 860s Get:18 http://ftpmaster.internal/ubuntu noble/main ppc64el cpp-13-powerpc64le-linux-gnu ppc64el 13.2.0-17ubuntu2 [10.7 MB] 860s Get:19 http://ftpmaster.internal/ubuntu noble/main ppc64el cpp-13 ppc64el 13.2.0-17ubuntu2 [1038 B] 860s Get:20 http://ftpmaster.internal/ubuntu noble/main ppc64el cpp-powerpc64le-linux-gnu ppc64el 4:13.2.0-7ubuntu1 [5330 B] 860s Get:21 http://ftpmaster.internal/ubuntu noble/main ppc64el cpp ppc64el 4:13.2.0-7ubuntu1 [22.5 kB] 860s Get:22 http://ftpmaster.internal/ubuntu noble/main ppc64el libcc1-0 ppc64el 14-20240303-1ubuntu1 [48.1 kB] 860s Get:23 http://ftpmaster.internal/ubuntu noble/main ppc64el libgomp1 ppc64el 14-20240303-1ubuntu1 [161 kB] 860s Get:24 http://ftpmaster.internal/ubuntu noble/main ppc64el libitm1 ppc64el 14-20240303-1ubuntu1 [32.4 kB] 860s Get:25 http://ftpmaster.internal/ubuntu noble/main ppc64el libatomic1 ppc64el 14-20240303-1ubuntu1 [10.7 kB] 860s Get:26 http://ftpmaster.internal/ubuntu noble/main ppc64el libasan8 ppc64el 14-20240303-1ubuntu1 [2973 kB] 860s Get:27 http://ftpmaster.internal/ubuntu noble/main ppc64el liblsan0 ppc64el 14-20240303-1ubuntu1 [1325 kB] 860s Get:28 http://ftpmaster.internal/ubuntu noble/main ppc64el libtsan2 ppc64el 14-20240303-1ubuntu1 [2734 kB] 860s Get:29 http://ftpmaster.internal/ubuntu noble/main ppc64el libubsan1 ppc64el 14-20240303-1ubuntu1 [1194 kB] 860s Get:30 http://ftpmaster.internal/ubuntu noble/main ppc64el libquadmath0 ppc64el 14-20240303-1ubuntu1 [158 kB] 860s Get:31 http://ftpmaster.internal/ubuntu noble/main ppc64el libgcc-13-dev ppc64el 13.2.0-17ubuntu2 [1581 kB] 860s Get:32 http://ftpmaster.internal/ubuntu noble/main ppc64el gcc-13-powerpc64le-linux-gnu ppc64el 13.2.0-17ubuntu2 [20.6 MB] 861s Get:33 http://ftpmaster.internal/ubuntu noble/main ppc64el gcc-13 ppc64el 13.2.0-17ubuntu2 [477 kB] 861s Get:34 http://ftpmaster.internal/ubuntu noble/main ppc64el gcc-powerpc64le-linux-gnu ppc64el 4:13.2.0-7ubuntu1 [1224 B] 861s Get:35 http://ftpmaster.internal/ubuntu noble/main ppc64el gcc ppc64el 4:13.2.0-7ubuntu1 [5022 B] 861s Get:36 http://ftpmaster.internal/ubuntu noble/main ppc64el libstdc++-13-dev ppc64el 13.2.0-17ubuntu2 [2445 kB] 861s Get:37 http://ftpmaster.internal/ubuntu noble/main ppc64el g++-13-powerpc64le-linux-gnu ppc64el 13.2.0-17ubuntu2 [12.2 MB] 861s Get:38 http://ftpmaster.internal/ubuntu noble/main ppc64el g++-13 ppc64el 13.2.0-17ubuntu2 [14.5 kB] 861s Get:39 http://ftpmaster.internal/ubuntu noble/main ppc64el g++-powerpc64le-linux-gnu ppc64el 4:13.2.0-7ubuntu1 [968 B] 861s Get:40 http://ftpmaster.internal/ubuntu noble/main ppc64el g++ ppc64el 4:13.2.0-7ubuntu1 [1086 B] 861s Get:41 http://ftpmaster.internal/ubuntu noble/main ppc64el build-essential ppc64el 12.10ubuntu1 [4936 B] 861s Get:42 http://ftpmaster.internal/ubuntu noble-proposed/main ppc64el zlib1g-dev ppc64el 1:1.3.dfsg-3.1ubuntu1 [902 kB] 861s Get:43 http://ftpmaster.internal/ubuntu noble/universe ppc64el libstreamvbyte-dev ppc64el 0.4.1-4ubuntu1 [6678 B] 862s Fetched 72.8 MB in 2s (30.8 MB/s) 862s Selecting previously unselected package libslow5-0:ppc64el. 862s (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 ... 69663 files and directories currently installed.) 862s Preparing to unpack .../00-libslow5-0_0.7.0+dfsg-2ubuntu4_ppc64el.deb ... 862s Unpacking libslow5-0:ppc64el (0.7.0+dfsg-2ubuntu4) ... 862s Selecting previously unselected package libslow5-dev:ppc64el. 862s Preparing to unpack .../01-libslow5-dev_0.7.0+dfsg-2ubuntu4_ppc64el.deb ... 862s Unpacking libslow5-dev:ppc64el (0.7.0+dfsg-2ubuntu4) ... 862s Selecting previously unselected package libstreamvbyte0:ppc64el. 862s Preparing to unpack .../02-libstreamvbyte0_0.4.1-4ubuntu1_ppc64el.deb ... 862s Unpacking libstreamvbyte0:ppc64el (0.4.1-4ubuntu1) ... 862s Selecting previously unselected package libblas3:ppc64el. 862s Preparing to unpack .../03-libblas3_3.12.0-3_ppc64el.deb ... 862s Unpacking libblas3:ppc64el (3.12.0-3) ... 862s Selecting previously unselected package libgfortran5:ppc64el. 862s Preparing to unpack .../04-libgfortran5_14-20240303-1ubuntu1_ppc64el.deb ... 862s Unpacking libgfortran5:ppc64el (14-20240303-1ubuntu1) ... 862s Selecting previously unselected package liblapack3:ppc64el. 862s Preparing to unpack .../05-liblapack3_3.12.0-3_ppc64el.deb ... 862s Unpacking liblapack3:ppc64el (3.12.0-3) ... 862s Selecting previously unselected package python3-numpy. 862s Preparing to unpack .../06-python3-numpy_1%3a1.24.2-2_ppc64el.deb ... 862s Unpacking python3-numpy (1:1.24.2-2) ... 863s Selecting previously unselected package python3-slow5. 863s Preparing to unpack .../07-python3-slow5_0.7.0+dfsg-2ubuntu4_ppc64el.deb ... 863s Unpacking python3-slow5 (0.7.0+dfsg-2ubuntu4) ... 863s Selecting previously unselected package libc-dev-bin. 863s Preparing to unpack .../08-libc-dev-bin_2.39-0ubuntu2_ppc64el.deb ... 863s Unpacking libc-dev-bin (2.39-0ubuntu2) ... 863s Selecting previously unselected package linux-libc-dev:ppc64el. 863s Preparing to unpack .../09-linux-libc-dev_6.8.0-11.11_ppc64el.deb ... 863s Unpacking linux-libc-dev:ppc64el (6.8.0-11.11) ... 863s Selecting previously unselected package libcrypt-dev:ppc64el. 863s Preparing to unpack .../10-libcrypt-dev_1%3a4.4.36-4_ppc64el.deb ... 863s Unpacking libcrypt-dev:ppc64el (1:4.4.36-4) ... 863s Selecting previously unselected package libtirpc-dev:ppc64el. 863s Preparing to unpack .../11-libtirpc-dev_1.3.4+ds-1build1_ppc64el.deb ... 863s Unpacking libtirpc-dev:ppc64el (1.3.4+ds-1build1) ... 863s Selecting previously unselected package libnsl-dev:ppc64el. 863s Preparing to unpack .../12-libnsl-dev_1.3.0-3_ppc64el.deb ... 863s Unpacking libnsl-dev:ppc64el (1.3.0-3) ... 863s Selecting previously unselected package rpcsvc-proto. 863s Preparing to unpack .../13-rpcsvc-proto_1.4.2-0ubuntu6_ppc64el.deb ... 863s Unpacking rpcsvc-proto (1.4.2-0ubuntu6) ... 863s Selecting previously unselected package libc6-dev:ppc64el. 863s Preparing to unpack .../14-libc6-dev_2.39-0ubuntu2_ppc64el.deb ... 863s Unpacking libc6-dev:ppc64el (2.39-0ubuntu2) ... 863s Selecting previously unselected package libisl23:ppc64el. 863s Preparing to unpack .../15-libisl23_0.26-3_ppc64el.deb ... 863s Unpacking libisl23:ppc64el (0.26-3) ... 863s Selecting previously unselected package libmpc3:ppc64el. 863s Preparing to unpack .../16-libmpc3_1.3.1-1_ppc64el.deb ... 863s Unpacking libmpc3:ppc64el (1.3.1-1) ... 863s Selecting previously unselected package cpp-13-powerpc64le-linux-gnu. 863s Preparing to unpack .../17-cpp-13-powerpc64le-linux-gnu_13.2.0-17ubuntu2_ppc64el.deb ... 863s Unpacking cpp-13-powerpc64le-linux-gnu (13.2.0-17ubuntu2) ... 863s Selecting previously unselected package cpp-13. 863s Preparing to unpack .../18-cpp-13_13.2.0-17ubuntu2_ppc64el.deb ... 863s Unpacking cpp-13 (13.2.0-17ubuntu2) ... 863s Selecting previously unselected package cpp-powerpc64le-linux-gnu. 863s Preparing to unpack .../19-cpp-powerpc64le-linux-gnu_4%3a13.2.0-7ubuntu1_ppc64el.deb ... 863s Unpacking cpp-powerpc64le-linux-gnu (4:13.2.0-7ubuntu1) ... 863s Selecting previously unselected package cpp. 863s Preparing to unpack .../20-cpp_4%3a13.2.0-7ubuntu1_ppc64el.deb ... 863s Unpacking cpp (4:13.2.0-7ubuntu1) ... 863s Selecting previously unselected package libcc1-0:ppc64el. 863s Preparing to unpack .../21-libcc1-0_14-20240303-1ubuntu1_ppc64el.deb ... 863s Unpacking libcc1-0:ppc64el (14-20240303-1ubuntu1) ... 863s Selecting previously unselected package libgomp1:ppc64el. 863s Preparing to unpack .../22-libgomp1_14-20240303-1ubuntu1_ppc64el.deb ... 863s Unpacking libgomp1:ppc64el (14-20240303-1ubuntu1) ... 863s Selecting previously unselected package libitm1:ppc64el. 863s Preparing to unpack .../23-libitm1_14-20240303-1ubuntu1_ppc64el.deb ... 863s Unpacking libitm1:ppc64el (14-20240303-1ubuntu1) ... 863s Selecting previously unselected package libatomic1:ppc64el. 863s Preparing to unpack .../24-libatomic1_14-20240303-1ubuntu1_ppc64el.deb ... 863s Unpacking libatomic1:ppc64el (14-20240303-1ubuntu1) ... 863s Selecting previously unselected package libasan8:ppc64el. 863s Preparing to unpack .../25-libasan8_14-20240303-1ubuntu1_ppc64el.deb ... 863s Unpacking libasan8:ppc64el (14-20240303-1ubuntu1) ... 863s Selecting previously unselected package liblsan0:ppc64el. 863s Preparing to unpack .../26-liblsan0_14-20240303-1ubuntu1_ppc64el.deb ... 863s Unpacking liblsan0:ppc64el (14-20240303-1ubuntu1) ... 863s Selecting previously unselected package libtsan2:ppc64el. 863s Preparing to unpack .../27-libtsan2_14-20240303-1ubuntu1_ppc64el.deb ... 863s Unpacking libtsan2:ppc64el (14-20240303-1ubuntu1) ... 863s Selecting previously unselected package libubsan1:ppc64el. 863s Preparing to unpack .../28-libubsan1_14-20240303-1ubuntu1_ppc64el.deb ... 863s Unpacking libubsan1:ppc64el (14-20240303-1ubuntu1) ... 863s Selecting previously unselected package libquadmath0:ppc64el. 863s Preparing to unpack .../29-libquadmath0_14-20240303-1ubuntu1_ppc64el.deb ... 863s Unpacking libquadmath0:ppc64el (14-20240303-1ubuntu1) ... 863s Selecting previously unselected package libgcc-13-dev:ppc64el. 863s Preparing to unpack .../30-libgcc-13-dev_13.2.0-17ubuntu2_ppc64el.deb ... 863s Unpacking libgcc-13-dev:ppc64el (13.2.0-17ubuntu2) ... 863s Selecting previously unselected package gcc-13-powerpc64le-linux-gnu. 863s Preparing to unpack .../31-gcc-13-powerpc64le-linux-gnu_13.2.0-17ubuntu2_ppc64el.deb ... 863s Unpacking gcc-13-powerpc64le-linux-gnu (13.2.0-17ubuntu2) ... 864s Selecting previously unselected package gcc-13. 864s Preparing to unpack .../32-gcc-13_13.2.0-17ubuntu2_ppc64el.deb ... 864s Unpacking gcc-13 (13.2.0-17ubuntu2) ... 864s Selecting previously unselected package gcc-powerpc64le-linux-gnu. 864s Preparing to unpack .../33-gcc-powerpc64le-linux-gnu_4%3a13.2.0-7ubuntu1_ppc64el.deb ... 864s Unpacking gcc-powerpc64le-linux-gnu (4:13.2.0-7ubuntu1) ... 864s Selecting previously unselected package gcc. 864s Preparing to unpack .../34-gcc_4%3a13.2.0-7ubuntu1_ppc64el.deb ... 864s Unpacking gcc (4:13.2.0-7ubuntu1) ... 864s Selecting previously unselected package libstdc++-13-dev:ppc64el. 864s Preparing to unpack .../35-libstdc++-13-dev_13.2.0-17ubuntu2_ppc64el.deb ... 864s Unpacking libstdc++-13-dev:ppc64el (13.2.0-17ubuntu2) ... 864s Selecting previously unselected package g++-13-powerpc64le-linux-gnu. 864s Preparing to unpack .../36-g++-13-powerpc64le-linux-gnu_13.2.0-17ubuntu2_ppc64el.deb ... 864s Unpacking g++-13-powerpc64le-linux-gnu (13.2.0-17ubuntu2) ... 864s Selecting previously unselected package g++-13. 864s Preparing to unpack .../37-g++-13_13.2.0-17ubuntu2_ppc64el.deb ... 864s Unpacking g++-13 (13.2.0-17ubuntu2) ... 864s Selecting previously unselected package g++-powerpc64le-linux-gnu. 864s Preparing to unpack .../38-g++-powerpc64le-linux-gnu_4%3a13.2.0-7ubuntu1_ppc64el.deb ... 864s Unpacking g++-powerpc64le-linux-gnu (4:13.2.0-7ubuntu1) ... 864s Selecting previously unselected package g++. 864s Preparing to unpack .../39-g++_4%3a13.2.0-7ubuntu1_ppc64el.deb ... 864s Unpacking g++ (4:13.2.0-7ubuntu1) ... 864s Selecting previously unselected package build-essential. 864s Preparing to unpack .../40-build-essential_12.10ubuntu1_ppc64el.deb ... 864s Unpacking build-essential (12.10ubuntu1) ... 864s Selecting previously unselected package zlib1g-dev:ppc64el. 864s Preparing to unpack .../41-zlib1g-dev_1%3a1.3.dfsg-3.1ubuntu1_ppc64el.deb ... 864s Unpacking zlib1g-dev:ppc64el (1:1.3.dfsg-3.1ubuntu1) ... 864s Selecting previously unselected package libstreamvbyte-dev:ppc64el. 864s Preparing to unpack .../42-libstreamvbyte-dev_0.4.1-4ubuntu1_ppc64el.deb ... 864s Unpacking libstreamvbyte-dev:ppc64el (0.4.1-4ubuntu1) ... 864s Setting up libstreamvbyte0:ppc64el (0.4.1-4ubuntu1) ... 864s Setting up linux-libc-dev:ppc64el (6.8.0-11.11) ... 864s Setting up libgomp1:ppc64el (14-20240303-1ubuntu1) ... 864s Setting up libblas3:ppc64el (3.12.0-3) ... 864s update-alternatives: using /usr/lib/powerpc64le-linux-gnu/blas/libblas.so.3 to provide /usr/lib/powerpc64le-linux-gnu/libblas.so.3 (libblas.so.3-powerpc64le-linux-gnu) in auto mode 864s Setting up libtirpc-dev:ppc64el (1.3.4+ds-1build1) ... 864s Setting up rpcsvc-proto (1.4.2-0ubuntu6) ... 864s Setting up libstreamvbyte-dev:ppc64el (0.4.1-4ubuntu1) ... 864s Setting up libquadmath0:ppc64el (14-20240303-1ubuntu1) ... 864s Setting up libmpc3:ppc64el (1.3.1-1) ... 864s Setting up libatomic1:ppc64el (14-20240303-1ubuntu1) ... 864s Setting up libslow5-0:ppc64el (0.7.0+dfsg-2ubuntu4) ... 864s Setting up libgfortran5:ppc64el (14-20240303-1ubuntu1) ... 864s Setting up libubsan1:ppc64el (14-20240303-1ubuntu1) ... 864s Setting up libnsl-dev:ppc64el (1.3.0-3) ... 864s Setting up libcrypt-dev:ppc64el (1:4.4.36-4) ... 864s Setting up libasan8:ppc64el (14-20240303-1ubuntu1) ... 864s Setting up libtsan2:ppc64el (14-20240303-1ubuntu1) ... 864s Setting up libisl23:ppc64el (0.26-3) ... 864s Setting up libc-dev-bin (2.39-0ubuntu2) ... 864s Setting up cpp-13-powerpc64le-linux-gnu (13.2.0-17ubuntu2) ... 864s Setting up libcc1-0:ppc64el (14-20240303-1ubuntu1) ... 864s Setting up liblsan0:ppc64el (14-20240303-1ubuntu1) ... 864s Setting up libitm1:ppc64el (14-20240303-1ubuntu1) ... 864s Setting up cpp-powerpc64le-linux-gnu (4:13.2.0-7ubuntu1) ... 864s Setting up liblapack3:ppc64el (3.12.0-3) ... 864s update-alternatives: using /usr/lib/powerpc64le-linux-gnu/lapack/liblapack.so.3 to provide /usr/lib/powerpc64le-linux-gnu/liblapack.so.3 (liblapack.so.3-powerpc64le-linux-gnu) in auto mode 864s Setting up cpp-13 (13.2.0-17ubuntu2) ... 864s Setting up libslow5-dev:ppc64el (0.7.0+dfsg-2ubuntu4) ... 864s Setting up python3-numpy (1:1.24.2-2) ... 866s Setting up libgcc-13-dev:ppc64el (13.2.0-17ubuntu2) ... 866s Setting up cpp (4:13.2.0-7ubuntu1) ... 866s Setting up libc6-dev:ppc64el (2.39-0ubuntu2) ... 866s Setting up libstdc++-13-dev:ppc64el (13.2.0-17ubuntu2) ... 866s Setting up gcc-13-powerpc64le-linux-gnu (13.2.0-17ubuntu2) ... 866s Setting up gcc-13 (13.2.0-17ubuntu2) ... 866s Setting up python3-slow5 (0.7.0+dfsg-2ubuntu4) ... 866s Setting up zlib1g-dev:ppc64el (1:1.3.dfsg-3.1ubuntu1) ... 866s Setting up g++-13-powerpc64le-linux-gnu (13.2.0-17ubuntu2) ... 866s Setting up gcc-powerpc64le-linux-gnu (4:13.2.0-7ubuntu1) ... 866s Setting up g++-powerpc64le-linux-gnu (4:13.2.0-7ubuntu1) ... 866s Setting up g++-13 (13.2.0-17ubuntu2) ... 866s Setting up gcc (4:13.2.0-7ubuntu1) ... 866s Setting up g++ (4:13.2.0-7ubuntu1) ... 866s update-alternatives: using /usr/bin/g++ to provide /usr/bin/c++ (c++) in auto mode 866s Setting up build-essential (12.10ubuntu1) ... 866s Setting up autopkgtest-satdep (0) ... 866s Processing triggers for man-db (2.12.0-3) ... 867s Processing triggers for libc-bin (2.39-0ubuntu2) ... 870s (Reading database ... 73629 files and directories currently installed.) 870s Removing autopkgtest-satdep (0) ... 875s autopkgtest [01:24:58]: test run-pkg-test: [----------------------- 875s Checking unit_test_ascii.c 876s Done! 876s Checking unit_test_binary.c 876s Done! 876s Checking unit_test_empty.c 876s Done! 876s Checking unit_test_enum.c 876s Done! 876s Checking unit_test_helpers.c 876s Done! 876s Checking unit_test_lossless.c 876s Done! 876s Checking unit_test_press.c 876s Done! 876s Checking unit_test_two_rg.c 876s Done! 877s autopkgtest [01:25:00]: test run-pkg-test: -----------------------] 877s autopkgtest [01:25:00]: test run-pkg-test: - - - - - - - - - - results - - - - - - - - - - 877s run-pkg-test PASS 877s autopkgtest [01:25:00]: @@@@@@@@@@@@@@@@@@@@ summary 877s run-pybinding-test PASS 877s run-pkg-test PASS 925s Creating nova instance adt-noble-ppc64el-libslow5lib-20240309-011023-juju-7f2275-prod-proposed-migration-environment-2 from image adt/ubuntu-noble-ppc64el-server-20240308.img (UUID ddb37fe7-ecfa-42b4-9389-74a2186e708a)... 925s Creating nova instance adt-noble-ppc64el-libslow5lib-20240309-011023-juju-7f2275-prod-proposed-migration-environment-2 from image adt/ubuntu-noble-ppc64el-server-20240308.img (UUID ddb37fe7-ecfa-42b4-9389-74a2186e708a)...