0s autopkgtest [11:17:10]: starting date and time: 2024-11-15 11:17:10+0000 0s autopkgtest [11:17:10]: git checkout: 0acbae0a WIP show VirtSubproc stderr in real-time 0s autopkgtest [11:17:10]: host juju-7f2275-prod-proposed-migration-environment-2; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.la09blwq/out --timeout-copy=6000 --setup-commands /home/ubuntu/autopkgtest-cloud/worker-config-production/setup-canonical.sh --apt-pocket=proposed=src:numpy --apt-upgrade libslow5lib --timeout-short=300 --timeout-copy=20000 --timeout-build=20000 --env=ADT_TEST_TRIGGERS=numpy/1:1.26.4+ds-11ubuntu1 -- ssh -s /home/ubuntu/autopkgtest/ssh-setup/nova -- --flavor builder-cpu2-ram4-disk20 --security-groups autopkgtest-juju-7f2275-prod-proposed-migration-environment-2@bos03-2.secgroup --name adt-plucky-amd64-libslow5lib-20241115-111709-juju-7f2275-prod-proposed-migration-environment-2-ca7a796c-12d9-4d9f-bc2f-52e720aaf9b2 --image adt/ubuntu-plucky-amd64-server --keyname testbed-juju-7f2275-prod-proposed-migration-environment-2 --net-id=net_prod-proposed-migration-amd64 -e TERM=linux -e ''"'"'http_proxy=http://squid.internal:3128'"'"'' -e ''"'"'https_proxy=http://squid.internal:3128'"'"'' -e ''"'"'no_proxy=127.0.0.1,127.0.1.1,login.ubuntu.com,localhost,localdomain,novalocal,internal,archive.ubuntu.com,ports.ubuntu.com,security.ubuntu.com,ddebs.ubuntu.com,changelogs.ubuntu.com,keyserver.ubuntu.com,launchpadlibrarian.net,launchpadcontent.net,launchpad.net,10.24.0.0/24,keystone.ps5.canonical.com,objectstorage.prodstack5.canonical.com'"'"'' --mirror=http://ftpmaster.internal/ubuntu/ 43s autopkgtest [11:17:53]: testbed dpkg architecture: amd64 44s autopkgtest [11:17:54]: testbed apt version: 2.9.8 44s autopkgtest [11:17:54]: @@@@@@@@@@@@@@@@@@@@ test bed setup 45s Get:1 http://ftpmaster.internal/ubuntu plucky-proposed InRelease [73.9 kB] 45s Get:2 http://ftpmaster.internal/ubuntu plucky-proposed/multiverse Sources [15.5 kB] 45s Get:3 http://ftpmaster.internal/ubuntu plucky-proposed/universe Sources [1056 kB] 45s Get:4 http://ftpmaster.internal/ubuntu plucky-proposed/restricted Sources [7016 B] 45s Get:5 http://ftpmaster.internal/ubuntu plucky-proposed/main Sources [94.5 kB] 45s Get:6 http://ftpmaster.internal/ubuntu plucky-proposed/main amd64 Packages [176 kB] 45s Get:7 http://ftpmaster.internal/ubuntu plucky-proposed/main i386 Packages [109 kB] 45s Get:8 http://ftpmaster.internal/ubuntu plucky-proposed/restricted amd64 Packages [32.6 kB] 45s Get:9 http://ftpmaster.internal/ubuntu plucky-proposed/universe amd64 Packages [833 kB] 45s Get:10 http://ftpmaster.internal/ubuntu plucky-proposed/universe i386 Packages [297 kB] 46s Get:11 http://ftpmaster.internal/ubuntu plucky-proposed/multiverse i386 Packages [740 B] 46s Get:12 http://ftpmaster.internal/ubuntu plucky-proposed/multiverse amd64 Packages [9416 B] 46s Fetched 2704 kB in 1s (2577 kB/s) 46s Reading package lists... 48s Reading package lists... 48s Building dependency tree... 48s Reading state information... 49s Calculating upgrade... 49s The following packages will be upgraded: 49s firmware-sof-signed grub-common grub-pc grub-pc-bin grub2-common libcap-ng0 49s libexpat1 lxd-installer man-db pastebinit python3-systemd xfsprogs 49s 12 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 49s Need to get 13.6 MB of archives. 49s After this operation, 477 kB of additional disk space will be used. 49s Get:1 http://ftpmaster.internal/ubuntu plucky/main amd64 firmware-sof-signed all 2024.06-1ubuntu2 [7083 kB] 50s Get:2 http://ftpmaster.internal/ubuntu plucky/main amd64 libcap-ng0 amd64 0.8.5-3build1 [15.6 kB] 50s Get:3 http://ftpmaster.internal/ubuntu plucky/main amd64 libexpat1 amd64 2.6.4-1 [94.9 kB] 50s Get:4 http://ftpmaster.internal/ubuntu plucky/main amd64 man-db amd64 2.13.0-1 [1352 kB] 50s Get:5 http://ftpmaster.internal/ubuntu plucky/main amd64 grub2-common amd64 2.12-5ubuntu7 [672 kB] 50s Get:6 http://ftpmaster.internal/ubuntu plucky/main amd64 grub-pc amd64 2.12-5ubuntu7 [137 kB] 50s Get:7 http://ftpmaster.internal/ubuntu plucky/main amd64 grub-pc-bin amd64 2.12-5ubuntu7 [1127 kB] 50s Get:8 http://ftpmaster.internal/ubuntu plucky/main amd64 grub-common amd64 2.12-5ubuntu7 [2110 kB] 50s Get:9 http://ftpmaster.internal/ubuntu plucky/main amd64 lxd-installer all 9 [5084 B] 50s Get:10 http://ftpmaster.internal/ubuntu plucky/main amd64 pastebinit all 1.7.1-1 [14.9 kB] 50s Get:11 http://ftpmaster.internal/ubuntu plucky/main amd64 python3-systemd amd64 235-1build5 [45.7 kB] 50s Get:12 http://ftpmaster.internal/ubuntu plucky/main amd64 xfsprogs amd64 6.8.0-2.2ubuntu2 [926 kB] 50s Preconfiguring packages ... 50s Fetched 13.6 MB in 1s (12.7 MB/s) 50s (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 ... 75542 files and directories currently installed.) 50s Preparing to unpack .../firmware-sof-signed_2024.06-1ubuntu2_all.deb ... 50s Unpacking firmware-sof-signed (2024.06-1ubuntu2) over (2024.06-1ubuntu1) ... 50s Preparing to unpack .../libcap-ng0_0.8.5-3build1_amd64.deb ... 50s Unpacking libcap-ng0:amd64 (0.8.5-3build1) over (0.8.5-1) ... 50s Setting up libcap-ng0:amd64 (0.8.5-3build1) ... 50s (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 ... 75568 files and directories currently installed.) 50s Preparing to unpack .../0-libexpat1_2.6.4-1_amd64.deb ... 50s Unpacking libexpat1:amd64 (2.6.4-1) over (2.6.2-2) ... 50s Preparing to unpack .../1-man-db_2.13.0-1_amd64.deb ... 51s Unpacking man-db (2.13.0-1) over (2.12.1-3) ... 51s Preparing to unpack .../2-grub2-common_2.12-5ubuntu7_amd64.deb ... 51s Unpacking grub2-common (2.12-5ubuntu7) over (2.12-5ubuntu5.1) ... 51s Preparing to unpack .../3-grub-pc_2.12-5ubuntu7_amd64.deb ... 51s Unpacking grub-pc (2.12-5ubuntu7) over (2.12-5ubuntu5.1) ... 51s Preparing to unpack .../4-grub-pc-bin_2.12-5ubuntu7_amd64.deb ... 51s Unpacking grub-pc-bin (2.12-5ubuntu7) over (2.12-5ubuntu5.1) ... 51s Preparing to unpack .../5-grub-common_2.12-5ubuntu7_amd64.deb ... 51s Unpacking grub-common (2.12-5ubuntu7) over (2.12-5ubuntu5.1) ... 51s Preparing to unpack .../6-lxd-installer_9_all.deb ... 51s Unpacking lxd-installer (9) over (8) ... 51s Preparing to unpack .../7-pastebinit_1.7.1-1_all.deb ... 51s Unpacking pastebinit (1.7.1-1) over (1.7.0-1) ... 51s Preparing to unpack .../8-python3-systemd_235-1build5_amd64.deb ... 51s Unpacking python3-systemd (235-1build5) over (235-1build4) ... 51s Preparing to unpack .../9-xfsprogs_6.8.0-2.2ubuntu2_amd64.deb ... 51s Unpacking xfsprogs (6.8.0-2.2ubuntu2) over (6.8.0-2.2ubuntu1) ... 51s Setting up libexpat1:amd64 (2.6.4-1) ... 51s Setting up firmware-sof-signed (2024.06-1ubuntu2) ... 51s Setting up pastebinit (1.7.1-1) ... 51s Setting up man-db (2.13.0-1) ... 51s Updating database of manual pages ... 53s man-db.service is a disabled or a static unit not running, not starting it. 53s Setting up grub-common (2.12-5ubuntu7) ... 53s update-rc.d: warning: start and stop actions are no longer supported; falling back to defaults 54s Setting up xfsprogs (6.8.0-2.2ubuntu2) ... 54s update-initramfs: deferring update (trigger activated) 54s Setting up lxd-installer (9) ... 54s Setting up python3-systemd (235-1build5) ... 54s Setting up grub2-common (2.12-5ubuntu7) ... 54s Setting up grub-pc-bin (2.12-5ubuntu7) ... 54s Setting up grub-pc (2.12-5ubuntu7) ... 55s Installing for i386-pc platform. 55s Installation finished. No error reported. 55s Sourcing file `/etc/default/grub' 55s Sourcing file `/etc/default/grub.d/50-cloudimg-settings.cfg' 55s Sourcing file `/etc/default/grub.d/90-autopkgtest.cfg' 55s Generating grub configuration file ... 55s Found linux image: /boot/vmlinuz-6.11.0-8-generic 55s Found initrd image: /boot/initrd.img-6.11.0-8-generic 55s Warning: os-prober will not be executed to detect other bootable partitions. 55s Systems on them will not be added to the GRUB boot configuration. 55s Check GRUB_DISABLE_OS_PROBER documentation entry. 55s Adding boot menu entry for UEFI Firmware Settings ... 55s done 55s Processing triggers for libc-bin (2.40-1ubuntu3) ... 55s Processing triggers for install-info (7.1.1-1) ... 56s Processing triggers for initramfs-tools (0.142ubuntu34) ... 56s update-initramfs: Generating /boot/initrd.img-6.11.0-8-generic 56s W: No lz4 in /usr/bin:/sbin:/bin, using gzip 63s Reading package lists... 63s Building dependency tree... 63s Reading state information... 63s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 63s Hit:1 http://ftpmaster.internal/ubuntu plucky-proposed InRelease 63s Hit:2 http://ftpmaster.internal/ubuntu plucky InRelease 63s Hit:3 http://ftpmaster.internal/ubuntu plucky-updates InRelease 64s Hit:4 http://ftpmaster.internal/ubuntu plucky-security InRelease 64s Reading package lists... 64s Reading package lists... 64s Building dependency tree... 64s Reading state information... 65s Calculating upgrade... 65s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 65s Reading package lists... 65s Building dependency tree... 65s Reading state information... 65s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 65s autopkgtest [11:18:15]: rebooting testbed after setup commands that affected boot 82s autopkgtest [11:18:32]: testbed running kernel: Linux 6.11.0-8-generic #8-Ubuntu SMP PREEMPT_DYNAMIC Mon Sep 16 13:41:20 UTC 2024 84s autopkgtest [11:18:34]: @@@@@@@@@@@@@@@@@@@@ apt-source libslow5lib 87s Get:1 http://ftpmaster.internal/ubuntu plucky/universe libslow5lib 0.7.0+dfsg-3 (dsc) [2584 B] 87s Get:2 http://ftpmaster.internal/ubuntu plucky/universe libslow5lib 0.7.0+dfsg-3 (tar) [2014 kB] 87s Get:3 http://ftpmaster.internal/ubuntu plucky/universe libslow5lib 0.7.0+dfsg-3 (diff) [8348 B] 87s gpgv: Signature made Wed Jul 24 20:44:11 2024 UTC 87s gpgv: using RSA key 8F91B227C7D6F2B1948C8236793CF67E8F0D11DA 87s gpgv: issuer "emollier@debian.org" 87s gpgv: Can't check signature: No public key 87s dpkg-source: warning: cannot verify inline signature for ./libslow5lib_0.7.0+dfsg-3.dsc: no acceptable signature found 88s autopkgtest [11:18:38]: testing package libslow5lib version 0.7.0+dfsg-3 88s autopkgtest [11:18:38]: build not needed 89s autopkgtest [11:18:39]: test run-pybinding-test: preparing testbed 90s Reading package lists... 90s Building dependency tree... 90s Reading state information... 91s Starting pkgProblemResolver with broken count: 0 91s Starting 2 pkgProblemResolver with broken count: 0 91s Done 91s The following additional packages will be installed: 91s libblas3 libgfortran5 liblapack3 libslow5-0t64 libslow5-dev libstreamvbyte0 91s python3-all python3-numpy python3-slow5 91s Suggested packages: 91s gcc gfortran python-numpy-doc python3-dev python3-pytest 91s The following NEW packages will be installed: 91s autopkgtest-satdep libblas3 libgfortran5 liblapack3 libslow5-0t64 91s libslow5-dev libstreamvbyte0 python3-all python3-numpy python3-slow5 91s 0 upgraded, 10 newly installed, 0 to remove and 0 not upgraded. 91s Need to get 9785 kB/9786 kB of archives. 91s After this operation, 58.7 MB of additional disk space will be used. 91s Get:1 /tmp/autopkgtest.X6B0sV/1-autopkgtest-satdep.deb autopkgtest-satdep amd64 0 [728 B] 91s Get:2 http://ftpmaster.internal/ubuntu plucky/main amd64 libblas3 amd64 3.12.0-3build2 [247 kB] 91s Get:3 http://ftpmaster.internal/ubuntu plucky/main amd64 libgfortran5 amd64 14.2.0-8ubuntu1 [909 kB] 92s Get:4 http://ftpmaster.internal/ubuntu plucky/main amd64 liblapack3 amd64 3.12.0-3build2 [2668 kB] 92s Get:5 http://ftpmaster.internal/ubuntu plucky/universe amd64 libslow5-0t64 amd64 0.7.0+dfsg-3 [69.1 kB] 92s Get:6 http://ftpmaster.internal/ubuntu plucky/universe amd64 libslow5-dev amd64 0.7.0+dfsg-3 [84.3 kB] 92s Get:7 http://ftpmaster.internal/ubuntu plucky/universe amd64 libstreamvbyte0 amd64 0.4.1-4ubuntu1 [6244 B] 92s Get:8 http://ftpmaster.internal/ubuntu plucky/main amd64 python3-all amd64 3.12.6-0ubuntu1 [886 B] 92s Get:9 http://ftpmaster.internal/ubuntu plucky-proposed/main amd64 python3-numpy amd64 1:1.26.4+ds-11ubuntu1 [5319 kB] 92s Get:10 http://ftpmaster.internal/ubuntu plucky/universe amd64 python3-slow5 amd64 0.7.0+dfsg-3 [482 kB] 92s Fetched 9785 kB in 1s (9730 kB/s) 92s Selecting previously unselected package libblas3:amd64. 92s (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 ... 75575 files and directories currently installed.) 92s Preparing to unpack .../0-libblas3_3.12.0-3build2_amd64.deb ... 92s Unpacking libblas3:amd64 (3.12.0-3build2) ... 92s Selecting previously unselected package libgfortran5:amd64. 92s Preparing to unpack .../1-libgfortran5_14.2.0-8ubuntu1_amd64.deb ... 92s Unpacking libgfortran5:amd64 (14.2.0-8ubuntu1) ... 92s Selecting previously unselected package liblapack3:amd64. 93s Preparing to unpack .../2-liblapack3_3.12.0-3build2_amd64.deb ... 93s Unpacking liblapack3:amd64 (3.12.0-3build2) ... 93s Selecting previously unselected package libslow5-0t64:amd64. 93s Preparing to unpack .../3-libslow5-0t64_0.7.0+dfsg-3_amd64.deb ... 93s Unpacking libslow5-0t64:amd64 (0.7.0+dfsg-3) ... 93s Selecting previously unselected package libslow5-dev:amd64. 93s Preparing to unpack .../4-libslow5-dev_0.7.0+dfsg-3_amd64.deb ... 93s Unpacking libslow5-dev:amd64 (0.7.0+dfsg-3) ... 93s Selecting previously unselected package libstreamvbyte0:amd64. 93s Preparing to unpack .../5-libstreamvbyte0_0.4.1-4ubuntu1_amd64.deb ... 93s Unpacking libstreamvbyte0:amd64 (0.4.1-4ubuntu1) ... 93s Selecting previously unselected package python3-all. 93s Preparing to unpack .../6-python3-all_3.12.6-0ubuntu1_amd64.deb ... 93s Unpacking python3-all (3.12.6-0ubuntu1) ... 93s Selecting previously unselected package python3-numpy. 93s Preparing to unpack .../7-python3-numpy_1%3a1.26.4+ds-11ubuntu1_amd64.deb ... 93s Unpacking python3-numpy (1:1.26.4+ds-11ubuntu1) ... 93s Selecting previously unselected package python3-slow5. 93s Preparing to unpack .../8-python3-slow5_0.7.0+dfsg-3_amd64.deb ... 93s Unpacking python3-slow5 (0.7.0+dfsg-3) ... 93s Selecting previously unselected package autopkgtest-satdep. 93s Preparing to unpack .../9-1-autopkgtest-satdep.deb ... 93s Unpacking autopkgtest-satdep (0) ... 93s Setting up libstreamvbyte0:amd64 (0.4.1-4ubuntu1) ... 93s Setting up python3-all (3.12.6-0ubuntu1) ... 93s Setting up libblas3:amd64 (3.12.0-3build2) ... 93s update-alternatives: using /usr/lib/x86_64-linux-gnu/blas/libblas.so.3 to provide /usr/lib/x86_64-linux-gnu/libblas.so.3 (libblas.so.3-x86_64-linux-gnu) in auto mode 93s Setting up libslow5-0t64:amd64 (0.7.0+dfsg-3) ... 93s Setting up libgfortran5:amd64 (14.2.0-8ubuntu1) ... 93s Setting up liblapack3:amd64 (3.12.0-3build2) ... 93s update-alternatives: using /usr/lib/x86_64-linux-gnu/lapack/liblapack.so.3 to provide /usr/lib/x86_64-linux-gnu/liblapack.so.3 (liblapack.so.3-x86_64-linux-gnu) in auto mode 93s Setting up libslow5-dev:amd64 (0.7.0+dfsg-3) ... 93s Setting up python3-numpy (1:1.26.4+ds-11ubuntu1) ... 94s Setting up python3-slow5 (0.7.0+dfsg-3) ... 94s Setting up autopkgtest-satdep (0) ... 94s Processing triggers for man-db (2.13.0-1) ... 95s Processing triggers for libc-bin (2.40-1ubuntu3) ... 97s (Reading database ... 76532 files and directories currently installed.) 97s Removing autopkgtest-satdep (0) ... 98s autopkgtest [11:18:48]: test run-pybinding-test: [----------------------- 98s Testing with python3.12 in /tmp/autopkgtest.X6B0sV/autopkgtest_tmp: 98s 15-Nov-24 11:18:48 - [DEBUG]: FILE: examples/example.slow5, mode: r 98s 15-Nov-24 11:18:48 - [DEBUG]: FILE: b'examples/example.slow5', mode: b'r' 98s 15-Nov-24 11:18:48 - [DEBUG]: Number of read_groups: 1 98s 15-Nov-24 11:18:48 - [DEBUG]: FILE: examples/example.slow5, mode: r 98s 15-Nov-24 11:18:48 - [DEBUG]: Creating/loading index... 98s [slow5_idx_init::INFO] Index file not found. Creating an index at 'examples/example.slow5.idx'. 98s 15-Nov-24 11:18:48 - [DEBUG]: get_aux_names starting 98s 15-Nov-24 11:18:48 - [DEBUG]: get_aux_names aux_len: 0 98s 15-Nov-24 11:18:48 - [WARNING]: get_aux_names ret is NULL 98s 15-Nov-24 11:18:48 - [DEBUG]: get_aux_types starting 98s 15-Nov-24 11:18:48 - [DEBUG]: get_aux_types aux_len: 0 98s 15-Nov-24 11:18:48 - [WARNING]: get_aux_types self.s5_aux_type is NULL 98s 15-Nov-24 11:18:48 - [WARNING]: get_read unknown aux name: read_number 98s 15-Nov-24 11:18:48 - [WARNING]: get_read unknown aux name: blah 98s 15-Nov-24 11:18:48 - [WARNING]: get_read unknown aux name: start_mux 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: -1 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next reached end of file (EOF)(-1): -1: ['SLOW5_ERR_EOF', 'End Of File reached'] 98s [slow5_idx_get::ERROR] Read ID 'null_read' was not found. At src/slow5_idx.c:441 98s 15-Nov-24 11:18:48 - [DEBUG]: get_read return not 0: -7 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_hdr_keys head_len: 32 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_hdr_keys head_len: 32 98s 15-Nov-24 11:18:48 - [DEBUG]: examples/example.slow5 closed 98s 15-Nov-24 11:18:48 - [DEBUG]: FILE: examples/example2.slow5, mode: r 98s 15-Nov-24 11:18:48 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r' 98s 15-Nov-24 11:18:48 - [DEBUG]: Number of read_groups: 4 98s 15-Nov-24 11:18:48 - [DEBUG]: FILE: examples/example2.slow5, mode: r 98s 15-Nov-24 11:18:48 - [DEBUG]: Creating/loading index... 98s [slow5_idx_init::INFO] Index file not found. Creating an index at 'examples/example2.slow5.idx'. 98s 15-Nov-24 11:18:48 - [DEBUG]: get_aux_names starting 98s 15-Nov-24 11:18:48 - [DEBUG]: get_aux_names aux_len: 5 98s 15-Nov-24 11:18:48 - [DEBUG]: get_aux_types starting 98s 15-Nov-24 11:18:48 - [DEBUG]: get_aux_types aux_len: 5 98s 15-Nov-24 11:18:48 - [WARNING]: get_read unknown aux name: blah 98s 15-Nov-24 11:18:48 - [WARNING]: get_read unknown aux name: blah 98s 15-Nov-24 11:18:48 - [DEBUG]: get_aux_names starting 98s 15-Nov-24 11:18:48 - [DEBUG]: get_aux_names aux_len: 5 98s 15-Nov-24 11:18:48 - [DEBUG]: get_aux_types starting 98s 15-Nov-24 11:18:48 - [DEBUG]: get_aux_types aux_len: 5 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: -1 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next reached end of file (EOF)(-1): -1: ['SLOW5_ERR_EOF', 'End Of File reached'] 98s 15-Nov-24 11:18:48 - [DEBUG]: examples/example2.slow5 closed 98s 15-Nov-24 11:18:48 - [DEBUG]: FILE: examples/example_write.slow5, mode: w 98s 15-Nov-24 11:18:48 - [DEBUG]: FILE: b'examples/example_write.slow5', mode: b'w' 98s 15-Nov-24 11:18:48 - [DEBUG]: Not writing blow5, skipping compression steps 98s 15-Nov-24 11:18:48 - [DEBUG]: FILE: examples/example2.slow5, mode: r 98s 15-Nov-24 11:18:48 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r' 98s 15-Nov-24 11:18:48 - [DEBUG]: Number of read_groups: 4 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation running 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checking header stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: writting header... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: header written 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() ret: 305872 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_free() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: function complete, returning 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation running 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() ret: 152707 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_free() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: function complete, returning 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation running 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() ret: 305872 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_free() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: function complete, returning 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation running 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() ret: 152707 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_free() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: function complete, returning 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation running 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() ret: 305872 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_free() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: function complete, returning 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation running 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() ret: 152707 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_free() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: function complete, returning 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation running 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() ret: 305906 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_free() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: function complete, returning 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation running 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() ret: 152741 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_free() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: function complete, returning 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: -1 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next reached end of file (EOF)(-1): -1: ['SLOW5_ERR_EOF', 'End Of File reached'] 98s 15-Nov-24 11:18:48 - [DEBUG]: examples/example_write.slow5 closed 98s 15-Nov-24 11:18:48 - [DEBUG]: examples/example2.slow5 closed 98s 15-Nov-24 11:18:48 - [DEBUG]: FILE: examples/example_write_append.blow5, mode: w 98s 15-Nov-24 11:18:48 - [DEBUG]: FILE: b'examples/example_write_append.blow5', mode: b'w' 98s 15-Nov-24 11:18:48 - [DEBUG]: examples/example_write.slow5 already closed 98s 15-Nov-24 11:18:48 - [DEBUG]: pathname: examples/example_write.slow5 98s 15-Nov-24 11:18:48 - [DEBUG]: total_time_slow5_get_next: 0.0 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: total_time_yield_reads: 0.0 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: total_single_write_time: 0.018725156784057617 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: total_multi_write_time: 0.0 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: FILE: examples/example2.slow5, mode: r 98s 15-Nov-24 11:18:48 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r' 98s 15-Nov-24 11:18:48 - [DEBUG]: Number of read_groups: 4 98s 15-Nov-24 11:18:48 - [DEBUG]: pathname: examples/example2.slow5 98s 15-Nov-24 11:18:48 - [DEBUG]: total_time_slow5_get_next: 0.010785341262817383 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: total_time_yield_reads: 0.011246681213378906 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: total_single_write_time: 0.0 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: total_multi_write_time: 0.0 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation running 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checking header stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: writting header... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: header written 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() ret: 152976 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_free() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: function complete, returning 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation running 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() ret: 76384 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_free() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: function complete, returning 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation running 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() ret: 152976 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_free() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: function complete, returning 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation running 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() ret: 76384 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_free() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: function complete, returning 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation running 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() ret: 152976 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_free() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: function complete, returning 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation running 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() ret: 76384 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_free() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: function complete, returning 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation running 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() ret: 153010 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_free() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: function complete, returning 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation running 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() ret: 76418 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_free() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: function complete, returning 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: -1 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next reached end of file (EOF)(-1): -1: ['SLOW5_ERR_EOF', 'End Of File reached'] 98s 15-Nov-24 11:18:48 - [DEBUG]: examples/example2.slow5 closed 98s 15-Nov-24 11:18:48 - [DEBUG]: examples/example_write_append.blow5 closed 98s 15-Nov-24 11:18:48 - [DEBUG]: FILE: examples/example_write_append.blow5, mode: a 98s 15-Nov-24 11:18:48 - [DEBUG]: FILE: b'examples/example_write_append.blow5', mode: b'a' 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_hdr_keys head_len: 38 98s |==============================================| 98s | pyslow5 test launch | 98s |==============================================| 98s ['__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'] 98s slow5 file opened and object created in: 0.0003 seconds 98s ============================================== 98s get_read check, r1 98s get_read in: 0.0024 seconds 98s read_id: r1 98s read_group: 0 98s digitisation: 8192.0 98s offset: 23.0 98s range: 1467.61 98s sampling_rate: 4000.0 98s len_raw_signal: 59676 98s signal: [1039 588 588 593 586 574 570 585 588 586] 98s pylen of signal: 59676 98s AUX FIELDS: 98s read_number: None 98s start_mux: None 98s blah: None 98s ============================================== 98s get_read check, r4, converte to pA 98s get_read in: 0.003 seconds 98s read_id: r4 98s read_group: 0 98s digitisation: 8192.0 98s offset: 23.0 98s range: 1467.61 98s sampling_rate: 4000.0 98s len_raw_signal: 59670 98s signal: [190.25902 108.92418 109.46163 109.10333 107.67012 108.38673 98s 108.745026 109.10333 111.074 108.38673 ] 98s pylen of signal: 59670 98s signal value type: 98s ============================================== 98s seq_reads check, all reads 98s seq_reads readIDs: 98s type check reads: 98s r1 98s r2 98s r3 98s r4 98s r5 98s seq_reads in: 0.0074 seconds 98s ============================================== 98s Yield check, selected reads 98s get_read_list in: 0.0 seconds 98s yielded readIDs: 98s r1 r1 98s r3 r3 98s null_read read not found, None returned 98s r5 r5 98s r2 r2 98s r1 r1 98s ============================================== 98s Get headder names 98s header names: 98s ['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'] 98s ============================================== 98s get_all_headers 98s {'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'} 98s ============================================== 98s Get headder attributes 98s flow_cell_id: FAB43577 98s exp_start_time: 1479433093 98s heatsink_temp: 33.9921875 98s asic_id: 3574887596 98s asic_id_eeprom: 0 98s asic_temp: 29.2145729 98s auto_update: 1 98s auto_update_source: https://mirror.oxfordnanoportal.com/software/MinKNOW/ 98s bream_core_version: 1.1.20.1 98s bream_is_standard: 1 98s bream_map_version: 1.1.20.1 98s bream_ont_version: 1.1.20.1 98s bream_prod_version: 1.1.20.1 98s bream_rnd_version: 0.1.1 98s device_id: MN16450 98s exp_script_name: python/recipes/nc/NC_48Hr_Sequencing_Run_FLO-MIN106_SQK-LSK108.py 98s exp_script_purpose: sequencing_run 98s exp_start_time: 1479433093 98s experiment_kit: genomic_dna 98s experiment_type: customer_qc 98s file_version: 1 98s filename: deamernanopore_20161117_fnfab43577_mn16450_sequencing_run_ma_821_r9_4_na12878_11_17_16_88738 98s flow_cell_id: FAB43577 98s heatsink_temp: 33.9921875 98s hostname: DEAMERNANOPORE 98s installation_type: map 98s local_firmware_file: 0 98s operating_system: Windows 6.2 98s protocol_run_id: a4429838-103c-497f-a824-7dffa72cfd81 98s protocols_version: 1.1.20 98s run_id: d6e473a6d513ec6bfc150c60fd4556d72f0e6d18 98s sample_frequency: 4000 98s usb_config: 1.0.11_ONT#MinION_fpga_1.0.1#ctrl#Auto 98s user_filename_input: ma_821_r9.4_na12878_11_17_16 98s version: 1.1.20 98s ============================================== 98s get_read check, 0d624d4b-671f-40b8-9798-84f2ccc4d7fc 98s read_id: 0d624d4b-671f-40b8-9798-84f2ccc4d7fc 98s read_group: 3 98s digitisation: 8192.0 98s offset: 6.0 98s range: 1444.86 98s sampling_rate: 4000.0 98s len_raw_signal: 38164 98s signal: [1462 1075 795 801 797 788 817 791 801 802] 98s pylen of signal: 38164 98s AUX FIELDS: 98s read_number: 2287 98s start_mux: 2 98s blah: None 98s AUX FIELDS: 98s blah: None 98s AUX FIELDS: 98s read_number: 2287 98s ============================================== 98s Get aux names 98s aux names: 98s ['channel_number', 'median_before', 'read_number', 'start_mux', 'start_time'] 98s ============================================== 98s Get aux types 98s aux types: 98s [22, 9, 2, 4, 7] 98s ============================================== 98s AUX FIELDS: 98s channel_number: 391 98s median_before: 260.557264 98s read_number: 2287 98s start_mux: 2 98s start_time: 36886851 98s ============================================== 98s seq_reads with aux: 98s type check reads: 98s r0 98s read_number 4019 98s r1 98s read_number 2287 98s r2 98s read_number 4019 98s r3 98s read_number 2287 98s r4 98s read_number 4019 98s r5 98s read_number 2287 98s 0a238451-b9ed-446d-a152-badd074006c4 98s read_number 4019 98s 0d624d4b-671f-40b8-9798-84f2ccc4d7fc 98s read_number 2287 98s ============================================== 98s write reads no aux 98s ret: write_header(): 0 98s ret: write_record(): 0 98s ret: write_record(): 0 98s ret: write_record(): 0 98s ret: write_record(): 0 98s ret: write_record(): 0 98s ret: write_record(): 0 98s ret: write_record(): 0 98s ret: write_record(): 0 98s ============================================== 98s append reads no aux 98s ret: write_header(): 0 98s ret: write_record(): 0 98s ret: write_record(): 0 98s ret: write_record(): 0 98s ret: write_record(): 0 98s ret: write_record(): 0 98s ret: write_record(): 0 98s ret: write_record(): 0 98s ret: write_record(): 0 98s get_all_headers 98s {'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'}15-Nov-24 11:18:48 - [DEBUG]: FILE: examples/example2.slow5, mode: r 98s 15-Nov-24 11:18:48 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r' 98s 15-Nov-24 11:18:48 - [DEBUG]: Number of read_groups: 4 98s 15-Nov-24 11:18:48 - [DEBUG]: pathname: examples/example2.slow5 98s 15-Nov-24 11:18:48 - [DEBUG]: total_time_slow5_get_next: 0.010667562484741211 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: total_time_yield_reads: 0.011065006256103516 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: total_single_write_time: 0.0 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: total_multi_write_time: 0.0 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation running 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() ret: 152983 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_free() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: function complete, returning 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation running 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() ret: 76391 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_free() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: function complete, returning 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation running 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() ret: 152983 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_free() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: function complete, returning 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation running 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() ret: 76391 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_free() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: function complete, returning 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation running 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() ret: 152983 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_free() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: function complete, returning 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation running 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() ret: 76391 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_free() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: function complete, returning 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation running 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() ret: 153017 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_free() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: function complete, returning 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation running 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() ret: 76425 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_free() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: function complete, returning 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: -1 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next reached end of file (EOF)(-1): -1: ['SLOW5_ERR_EOF', 'End Of File reached'] 98s 15-Nov-24 11:18:48 - [DEBUG]: examples/example2.slow5 closed 98s 15-Nov-24 11:18:48 - [DEBUG]: examples/example_write_append.blow5 closed 98s 15-Nov-24 11:18:48 - [DEBUG]: FILE: examples/example_write_aux.blow5, mode: w 98s 15-Nov-24 11:18:48 - [DEBUG]: FILE: b'examples/example_write_aux.blow5', mode: b'w' 98s 15-Nov-24 11:18:48 - [DEBUG]: examples/example_write_append.blow5 already closed 98s 15-Nov-24 11:18:48 - [DEBUG]: pathname: examples/example_write_append.blow5 98s 15-Nov-24 11:18:48 - [DEBUG]: total_time_slow5_get_next: 0.0 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: total_time_yield_reads: 0.0 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: total_single_write_time: 0.018439531326293945 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: total_multi_write_time: 0.0 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: FILE: examples/example2.slow5, mode: r 98s 15-Nov-24 11:18:48 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r' 98s 15-Nov-24 11:18:48 - [DEBUG]: Number of read_groups: 4 98s 15-Nov-24 11:18:48 - [DEBUG]: pathname: examples/example2.slow5 98s 15-Nov-24 11:18:48 - [DEBUG]: total_time_slow5_get_next: 0.010901927947998047 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: total_time_yield_reads: 0.011328458786010742 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: total_single_write_time: 0.0 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: total_multi_write_time: 0.0 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: get_aux_names starting 98s 15-Nov-24 11:18:48 - [DEBUG]: get_aux_names aux_len: 5 98s 15-Nov-24 11:18:48 - [DEBUG]: get_aux_types starting 98s 15-Nov-24 11:18:48 - [DEBUG]: get_aux_types aux_len: 5 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation running 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checking header stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: writting header... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: header written 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: channel_number: 281 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string running... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string type: 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: median_before: 231.363533 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: read_number: 4019 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: start_mux: 1 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: start_time: 78470500 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: aux stuff done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() ret: 67258 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_free() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: function complete, returning 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation running 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: channel_number: 391 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string running... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string type: 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: median_before: 260.557264 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: read_number: 2287 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: start_mux: 2 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: start_time: 36886851 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: aux stuff done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() ret: 32408 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_free() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: function complete, returning 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation running 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: channel_number: 281 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string running... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string type: 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: median_before: 231.363533 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: read_number: 4019 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: start_mux: 1 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: start_time: 78470500 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: aux stuff done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() ret: 67258 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_free() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: function complete, returning 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation running 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: channel_number: 391 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string running... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string type: 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: median_before: 260.557264 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: read_number: 2287 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: start_mux: 2 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: start_time: 36886851 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: aux stuff done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() ret: 32408 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_free() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: function complete, returning 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation running 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: channel_number: 281 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string running... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string type: 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: median_before: 231.363533 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: read_number: 4019 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: start_mux: 1 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: start_time: 78470500 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: aux stuff done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() ret: 67260 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_free() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: function complete, returning 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation running 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: channel_number: 391 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string running... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string type: 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: median_before: 260.557264 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: read_number: 2287 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: start_mux: 2 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: start_time: 36886851 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: aux stuff done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() ret: 32408 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_free() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: function complete, returning 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation running 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: channel_number: 281 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string running... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string type: 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: median_before: 231.363533 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: read_number: 4019 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: start_mux: 1 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: start_time: 78470500 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: aux stuff done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() ret: 67298 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_free() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: function complete, returning 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation running 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: channel_number: 391 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string running... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string type: 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: median_before: 260.557264 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: read_number: 2287 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: start_mux: 2 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: start_time: 36886851 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: aux stuff done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() ret: 32446 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_free() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: function complete, returning 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: -1 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next reached end of file (EOF)(-1): -1: ['SLOW5_ERR_EOF', 'End Of File reached'] 98s 15-Nov-24 11:18:48 - [DEBUG]: examples/example2.slow5 closed 98s 15-Nov-24 11:18:48 - [DEBUG]: examples/example_write_aux.blow5 closed 98s 15-Nov-24 11:18:48 - [DEBUG]: FILE: examples/example_write_append_aux.blow5, mode: w 98s 15-Nov-24 11:18:48 - [DEBUG]: FILE: b'examples/example_write_append_aux.blow5', mode: b'w' 98s 15-Nov-24 11:18:48 - [DEBUG]: examples/example_write_aux.blow5 already closed 98s 15-Nov-24 11:18:48 - [DEBUG]: pathname: examples/example_write_aux.blow5 98s 15-Nov-24 11:18:48 - [DEBUG]: total_time_slow5_get_next: 0.0 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: total_time_yield_reads: 0.0 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: total_single_write_time: 0.018904924392700195 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: total_multi_write_time: 0.0 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: FILE: examples/example2.slow5, mode: r 98s 15-Nov-24 11:18:48 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r' 98s 15-Nov-24 11:18:48 - [DEBUG]: Number of read_groups: 4 98s 15-Nov-24 11:18:48 - [DEBUG]: pathname: examples/example2.slow5 98s 15-Nov-24 11:18:48 - [DEBUG]: total_time_slow5_get_next: 0.010677337646484375 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: total_time_yield_reads: 0.011250972747802734 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: total_single_write_time: 0.0 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: total_multi_write_time: 0.0 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: get_aux_names starting 98s 15-Nov-24 11:18:48 - [DEBUG]: get_aux_names aux_len: 5 98s 15-Nov-24 11:18:48 - [DEBUG]: get_aux_types starting 98s 15-Nov-24 11:18:48 - [DEBUG]: get_aux_types aux_len: 5 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation running 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checking header stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: writting header... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: header written 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: channel_number: 281 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string running... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string type: 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: median_before: 231.363533 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: read_number: 4019 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: start_mux: 1 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: start_time: 78470500 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: aux stuff done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() ret: 153008 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_free() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: function complete, returning 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation running 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: channel_number: 391 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string running... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string type: 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: median_before: 260.557264 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: read_number: 2287 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: start_mux: 2 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: start_time: 36886851 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: aux stuff done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() ret: 76416 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_free() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: function complete, returning 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation running 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: channel_number: 281 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string running... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string type: 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: median_before: 231.363533 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: read_number: 4019 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: start_mux: 1 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: start_time: 78470500 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: aux stuff done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() ret: 153008 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_free() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: function complete, returning 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation running 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: channel_number: 391 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string running... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string type: 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: median_before: 260.557264 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: read_number: 2287 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: start_mux: 2 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: start_time: 36886851 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: aux stuff done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() ret: 76416 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_free() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: function complete, returning 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation running 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: channel_number: 281 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string running... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string type: 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: median_before: 231.363533 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: read_number: 4019 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: start_mux: 1 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: start_time: 78470500 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: aux stuff done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() ret: 153008 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_free() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: function complete, returning 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation running 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: channel_number: 391 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string running... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string type: 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: median_before: 260.557264 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: read_number: 2287 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: start_mux: 2 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: start_time: 36886851 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: aux stuff done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() ret: 76416 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_free() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: function complete, returning 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation running 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: channel_number: 281 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string running... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string type: 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: median_before: 231.363533 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: read_number: 4019 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: start_mux: 1 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: start_time: 78470500 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: aux stuff done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() ret: 153042 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_free() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: function complete, returning 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation running 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: channel_number: 391 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string running... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string type: 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: median_before: 260.557264 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: read_number: 2287 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: start_mux: 2 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: start_time: 36886851 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: aux stuff done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() ret: 76450 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_free() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: function complete, returning 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: -1 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next reached end of file (EOF)(-1): -1: ['SLOW5_ERR_EOF', 'End Of File reached'] 98s 15-Nov-24 11:18:48 - [DEBUG]: examples/example2.slow5 closed 98s 15-Nov-24 11:18:48 - [DEBUG]: examples/example_write_append_aux.blow5 closed 98s 15-Nov-24 11:18:48 - [DEBUG]: FILE: examples/example_write_append_aux.blow5, mode: a 98s 15-Nov-24 11:18:48 - [DEBUG]: FILE: b'examples/example_write_append_aux.blow5', mode: b'a' 98s 15-Nov-24 11:18:48 - [DEBUG]: examples/example_write_append.blow5 already closed 98s 15-Nov-24 11:18:48 - [DEBUG]: pathname: examples/example_write_append.blow5 98s 15-Nov-24 11:18:48 - [DEBUG]: total_time_slow5_get_next: 0.0 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: total_time_yield_reads: 0.0 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: total_single_write_time: 0.01891016960144043 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: total_multi_write_time: 0.0 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: FILE: examples/example2.slow5, mode: r 98s 15-Nov-24 11:18:48 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r' 98s 15-Nov-24 11:18:48 - [DEBUG]: Number of read_groups: 4 98s 15-Nov-24 11:18:48 - [DEBUG]: pathname: examples/example2.slow5 98s 15-Nov-24 11:18:48 - [DEBUG]: total_time_slow5_get_next: 0.010800600051879883 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: total_time_yield_reads: 0.011401176452636719 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: total_single_write_time: 0.0 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: total_multi_write_time: 0.0 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: get_aux_names starting 98s 15-Nov-24 11:18:48 - [DEBUG]: get_aux_names aux_len: 5 98s 15-Nov-24 11:18:48 - [DEBUG]: get_aux_types starting 98s 15-Nov-24 11:18:48 - [DEBUG]: get_aux_types aux_len: 5 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation running 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: channel_number: 281 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string running... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string type: 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: median_before: 231.363533 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: read_number: 4019 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: start_mux: 1 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: start_time: 78470500 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: aux stuff done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() ret: 153015 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_free() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: function complete, returning 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation running 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: channel_number: 391 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string running... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string type: 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: median_before: 260.557264 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: read_number: 2287 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: start_mux: 2 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: start_time: 36886851 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: aux stuff done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() ret: 76423 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_free() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: function complete, returning 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation running 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: channel_number: 281 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string running... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string type: 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: median_before: 231.363533 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: read_number: 4019 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: start_mux: 1 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: start_time: 78470500 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: aux stuff done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() ret: 153015 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_free() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: function complete, returning 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation running 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: channel_number: 391 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string running... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string type: 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: median_before: 260.557264 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: read_number: 2287 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: start_mux: 2 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: start_time: 36886851 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: aux stuff done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() ret: 76423 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_free() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: function complete, returning 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation running 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: channel_number: 281 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string running... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string type: 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: median_before: 231.363533 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: read_number: 4019 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: start_mux: 1 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: start_time: 78470500 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: aux stuff done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() ret: 153015 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_free() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: function complete, returning 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation running 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: channel_number: 391 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string running... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string type: 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: median_before: 260.557264 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: read_number: 2287 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: start_mux: 2 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: start_time: 36886851 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: aux stuff done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() ret: 76423 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_free() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: function complete, returning 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation running 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: channel_number: 281 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string running... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string type: 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: median_before: 231.363533 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: read_number: 4019 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: start_mux: 1 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: start_time: 78470500 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: aux stuff done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() ret: 153049 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_free() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: function complete, returning 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation running 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: _record_type_validation done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: channel_number: 391 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string running... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string type: 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: median_before: 260.557264 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: read_number: 2287 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: start_mux: 2 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: checked_aux: start_time: 36886851 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: aux stuff done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_write() ret: 76457 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: slow5_rec_free() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record: function complete, returning 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: -1 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next reached end of file (EOF)(-1): -1: ['SLOW5_ERR_EOF', 'End Of File reached'] 98s 15-Nov-24 11:18:48 - [DEBUG]: examples/example2.slow5 closed 98s 15-Nov-24 11:18:48 - [DEBUG]: examples/example_write_append_aux.blow5 closed 98s 15-Nov-24 11:18:48 - [DEBUG]: FILE: examples/example2.slow5, mode: r 98s 15-Nov-24 11:18:48 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r' 98s 15-Nov-24 11:18:48 - [DEBUG]: Number of read_groups: 4 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next_multi return: 3 98s 15-Nov-24 11:18:48 - [DEBUG]: get_aux_names starting 98s 15-Nov-24 11:18:48 - [DEBUG]: get_aux_names aux_len: 5 98s 15-Nov-24 11:18:48 - [DEBUG]: get_aux_types starting 98s 15-Nov-24 11:18:48 - [DEBUG]: get_aux_types aux_len: 5 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next_multi return: 3 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next_multi return: 2 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next_multi has no more batches - batchsize:3 ret:2 98s 15-Nov-24 11:18:48 - [DEBUG]: seq_reads_multi timings: 98s 15-Nov-24 11:18:48 - [DEBUG]: aux_total_time: 0.00015020370483398438 98s 15-Nov-24 11:18:48 - [DEBUG]: primary_total_time: 0.00013756752014160156 98s 15-Nov-24 11:18:48 - [DEBUG]: pA_total_time: 0.0007126331329345703 98s 15-Nov-24 11:18:48 - [DEBUG]: signal_total_time: 0.0001270771026611328 98s 15-Nov-24 11:18:48 - [DEBUG]: examples/example2.slow5 closed 98s 15-Nov-24 11:18:48 - [DEBUG]: FILE: examples/example2.slow5, mode: r 98s 15-Nov-24 11:18:48 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r' 98s 15-Nov-24 11:18:48 - [DEBUG]: Number of read_groups: 4 98s 15-Nov-24 11:18:48 - [DEBUG]: pathname: examples/example2.slow5 98s 15-Nov-24 11:18:48 - [DEBUG]: total_time_slow5_get_next: 0.01582813262939453 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: total_time_yield_reads: 0.0010285377502441406 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: total_single_write_time: 0.0 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: total_multi_write_time: 0.0 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: FILE: examples/example2.slow5, mode: r 98s 15-Nov-24 11:18:48 - [DEBUG]: Creating/loading index... 98s 15-Nov-24 11:18:48 - [DEBUG]: Setting up batching... 98s 15-Nov-24 11:18:48 - [DEBUG]: read_list: ['r0', 'r1', 'r2', 'r3', 'r4', 'r5', '0a238451-b9ed-446d-a152-badd074006c4', '0d624d4b-671f-40b8-9798-84f2ccc4d7fc'] 98s 15-Nov-24 11:18:48 - [DEBUG]: batch for loop start 98s 15-Nov-24 11:18:48 - [DEBUG]: Batch: r0,r1,r2 98s 15-Nov-24 11:18:48 - [DEBUG]: Starting rid assignment 98s 15-Nov-24 11:18:48 - [DEBUG]: readID: r0, bin: b'r0' 98s 15-Nov-24 11:18:48 - [DEBUG]: readID: r1, bin: b'r1' 98s 15-Nov-24 11:18:48 - [DEBUG]: readID: r2, bin: b'r2' 98s 15-Nov-24 11:18:48 - [DEBUG]: rid assignment complete 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_batch: num_reads: 3 98s 15-Nov-24 11:18:48 - [DEBUG]: get_read_multi slow5_get_batch ret: 3 98s 15-Nov-24 11:18:48 - [DEBUG]: get_aux_names starting 98s 15-Nov-24 11:18:48 - [DEBUG]: get_aux_names aux_len: 5 98s 15-Nov-24 11:18:48 - [DEBUG]: get_aux_types starting 98s 15-Nov-24 11:18:48 - [DEBUG]: get_aux_types aux_len: 5 98s 15-Nov-24 11:18:48 - [DEBUG]: Batch: r3,r4,r5 98s 15-Nov-24 11:18:48 - [DEBUG]: Starting rid assignment 98s 15-Nov-24 11:18:48 - [DEBUG]: readID: r3, bin: b'r3' 98s 15-Nov-24 11:18:48 - [DEBUG]: readID: r4, bin: b'r4' 98s 15-Nov-24 11:18:48 - [DEBUG]: readID: r5, bin: b'r5' 98s 15-Nov-24 11:18:48 - [DEBUG]: rid assignment complete 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_batch: num_reads: 3 98s 15-Nov-24 11:18:48 - [DEBUG]: get_read_multi slow5_get_batch ret: 3 98s 15-Nov-24 11:18:48 - [DEBUG]: Batch: 0a238451-b9ed-446d-a152-badd074006c4,0d624d4b-671f-40b8-9798-84f2ccc4d7fc 98s 15-Nov-24 11:18:48 - [DEBUG]: Starting rid assignment 98s 15-Nov-24 11:18:48 - [DEBUG]: readID: 0a238451-b9ed-446d-a152-badd074006c4, bin: b'0a238451-b9ed-446d-a152-badd074006c4' 98s 15-Nov-24 11:18:48 - [DEBUG]: readID: 0d624d4b-671f-40b8-9798-84f2ccc4d7fc, bin: b'0d624d4b-671f-40b8-9798-84f2ccc4d7fc' 98s 15-Nov-24 11:18:48 - [DEBUG]: rid assignment complete 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_batch: num_reads: 2 98s 15-Nov-24 11:18:48 - [DEBUG]: get_read_multi slow5_get_batch ret: 2 98s 15-Nov-24 11:18:48 - [DEBUG]: seq_reads_multi timings: 98s 15-Nov-24 11:18:48 - [DEBUG]: examples/example2.slow5 closed 98s 15-Nov-24 11:18:48 - [DEBUG]: FILE: examples/example_write_aux_multi.slow5, mode: w 98s 15-Nov-24 11:18:48 - [DEBUG]: FILE: b'examples/example_write_aux_multi.slow5', mode: b'w' 98s 15-Nov-24 11:18:48 - [DEBUG]: Not writing blow5, skipping compression steps 98s 15-Nov-24 11:18:48 - [DEBUG]: examples/example_write_append_aux.blow5 already closed 98s 15-Nov-24 11:18:48 - [DEBUG]: pathname: examples/example_write_append_aux.blow5 98s 15-Nov-24 11:18:48 - [DEBUG]: total_time_slow5_get_next: 0.0 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: total_time_yield_reads: 0.0 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: total_single_write_time: 0.01870417594909668 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: total_multi_write_time: 0.0 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: FILE: examples/example2.slow5, mode: r 98s 15-Nov-24 11:18:48 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r' 98s 15-Nov-24 11:18:48 - [DEBUG]: Number of read_groups: 4 98s 15-Nov-24 11:18:48 - [DEBUG]: pathname: examples/example2.slow5 98s 15-Nov-24 11:18:48 - [DEBUG]: total_time_slow5_get_next: 0.010936260223388672 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: total_time_yield_reads: 0.01154184341430664 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: total_single_write_time: 0.0 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: total_multi_write_time: 0.0 seconds 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: get_aux_names starting 98s 15-Nov-24 11:18:48 - [DEBUG]: get_aux_names aux_len: 5 98s 15-Nov-24 11:18:48 - [DEBUG]: get_aux_types starting 98s 15-Nov-24 11:18:48 - [DEBUG]: get_aux_types aux_len: 5 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: 0 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next return: -1 98s 15-Nov-24 11:18:48 - [DEBUG]: slow5_get_next reached end of file (EOF)(-1): -1: ['SLOW5_ERR_EOF', 'End Of File reached'] 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: Setting up batching... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: batch for loop start 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: _record_type_validation running 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux stuff done 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux stuff done 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux stuff done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: _record_type_validation done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: checking header stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: writting header... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: header written 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: checked_aux: channel_number: 281 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: slow5_aux_set_string running... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: slow5_aux_set_string type: 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: slow5_aux_set_string running done: ret = 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: checked_aux: median_before: 231.363533 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: checked_aux: read_number: 4019 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: checked_aux: start_mux: 1 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: checked_aux: start_time: 78470500 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: aux stuff done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: checked_aux: channel_number: 391 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: slow5_aux_set_string running... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: slow5_aux_set_string type: 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: slow5_aux_set_string running done: ret = 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: checked_aux: median_before: 260.557264 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: checked_aux: read_number: 2287 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: checked_aux: start_mux: 2 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: checked_aux: start_time: 36886851 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: aux stuff done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: checked_aux: channel_number: 281 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: slow5_aux_set_string running... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: slow5_aux_set_string type: 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: slow5_aux_set_string running done: ret = 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: checked_aux: median_before: 231.363533 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: checked_aux: read_number: 4019 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: checked_aux: start_mux: 1 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: checked_aux: start_time: 78470500 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: aux stuff done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: slow5_write_batch() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: free() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: free() aux 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: _record_type_validation running 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux stuff done 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux stuff done 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 98s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux stuff done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: _record_type_validation done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: checked_aux: channel_number: 391 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: slow5_aux_set_string running... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: slow5_aux_set_string type: 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: slow5_aux_set_string running done: ret = 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: checked_aux: median_before: 260.557264 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: checked_aux: read_number: 2287 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: checked_aux: start_mux: 2 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: checked_aux: start_time: 36886851 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: aux stuff done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: checked_aux: channel_number: 281 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: slow5_aux_set_string running... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: slow5_aux_set_string type: 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: slow5_aux_set_string running done: ret = 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: checked_aux: median_before: 231.363533 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: checked_aux: read_number: 4019 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: checked_aux: start_mux: 1 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: checked_aux: start_time: 78470500 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: aux stuff done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: slow5_rec_init() 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: self.write assignments... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: self.write.raw_signal malloc... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: self.write.raw_signal malloc done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: self.write assignments done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: self.write processing raw_signal 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: self.write raw_signal done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: aux stuff... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: checked_aux: channel_number: 391 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: slow5_aux_set_string running... 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: slow5_aux_set_string type: 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: slow5_aux_set_string running done: ret = 0 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: checked_aux: median_before: 260.557264 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: checked_aux: read_number: 2287 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: checked_aux: start_mux: 2 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: checked_aux: start_time: 36886851 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: aux stuff done 98s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: slow5_write_batch() 99s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: free() 99s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: free() aux 99s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: _record_type_validation running 99s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 99s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 99s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 99s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 99s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 99s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 99s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux stuff done 99s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: doing aux stuff... 99s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 99s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 99s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 99s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 99s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux passed tests... 99s 15-Nov-24 11:18:48 - [DEBUG]: _record_type_validation: aux stuff done 99s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: _record_type_validation done 99s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: slow5_rec_init() 99s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: self.write assignments... 99s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: self.write.raw_signal malloc... 99s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: self.write.raw_signal malloc done 99s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: self.write assignments done 99s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: self.write processing raw_signal 99s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: self.write raw_signal done 99s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: aux stuff... 99s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: checked_aux: channel_number: 281 99s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: slow5_aux_set_string running... 99s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: slow5_aux_set_string type: 99s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: slow5_aux_set_string running done: ret = 0 99s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: checked_aux: median_before: 231.363533 99s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: checked_aux: read_number: 4019 99s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: checked_aux: start_mux: 1 99s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: checked_aux: start_time: 78470500 99s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: aux stuff done 99s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: slow5_rec_init() 99s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: self.write assignments... 99s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: self.write.raw_signal malloc... 99s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: self.write.raw_signal malloc done 99s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: self.write assignments done 99s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: self.write processing raw_signal 99s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: self.write raw_signal done 99s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: aux stuff... 99s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: checked_aux: channel_number: 391 99s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: slow5_aux_set_string running... 99s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: slow5_aux_set_string type: 99s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: slow5_aux_set_string running done: ret = 0 99s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: checked_aux: median_before: 260.557264 99s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: checked_aux: read_number: 2287 99s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: checked_aux: start_mux: 2 99s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: checked_aux: start_time: 36886851 99s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: aux stuff done 99s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: slow5_write_batch() 99s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: free() 99s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: free() aux 99s 15-Nov-24 11:18:48 - [DEBUG]: write_record_batch: function complete, returning 0 99s 15-Nov-24 11:18:48 - [DEBUG]: examples/example2.slow5 closed 99s 15-Nov-24 11:18:48 - [DEBUG]: examples/example_write_aux_multi.slow5 closed 99s 15-Nov-24 11:18:48 - [DEBUG]: FILE: examples/example2.slow5, mode: r 99s 15-Nov-24 11:18:48 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r' 99s 15-Nov-24 11:18:48 - [DEBUG]: Number of read_groups: 4 99s 15-Nov-24 11:18:48 - [DEBUG]: pathname: examples/example2.slow5 99s 15-Nov-24 11:18:48 - [DEBUG]: total_time_slow5_get_next: 0.010949373245239258 seconds 99s 15-Nov-24 11:18:48 - [DEBUG]: total_time_yield_reads: 0.011553525924682617 seconds 99s 15-Nov-24 11:18:48 - [DEBUG]: total_single_write_time: 0.0 seconds 99s 15-Nov-24 11:18:48 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 99s 15-Nov-24 11:18:48 - [DEBUG]: total_multi_write_time: 0.0 seconds 99s 15-Nov-24 11:18:48 - [DEBUG]: FILE: examples/example2.slow5, mode: r 99s 15-Nov-24 11:18:48 - [DEBUG]: Creating/loading index... 99s 15-Nov-24 11:18:48 - [DEBUG]: examples/example2.slow5 closed 99s 99s ret: write_record(): 0 99s ret: write_record(): 0 99s ret: write_record(): 0 99s ret: write_record(): 0 99s ret: write_record(): 0 99s ret: write_record(): 0 99s ret: write_record(): 0 99s ret: write_record(): 0 99s ============================================== 99s write reads with aux 99s ret: write_header(): 0 99s ret: write_header(): 0 99s ret: write_record(): 0 99s ret: write_record(): 0 99s ret: write_record(): 0 99s ret: write_record(): 0 99s ret: write_record(): 0 99s ret: write_record(): 0 99s ret: write_record(): 0 99s ret: write_record(): 0 99s ============================================== 99s append reads with aux 99s ret: write_header(): 0 99s ret: write_header(): 0 99s ret: write_record(): 0 99s ret: write_record(): 0 99s ret: write_record(): 0 99s ret: write_record(): 0 99s ret: write_record(): 0 99s ret: write_record(): 0 99s ret: write_record(): 0 99s ret: write_record(): 0 99s ret: write_record(): 0 99s ret: write_record(): 0 99s ret: write_record(): 0 99s ret: write_record(): 0 99s ret: write_record(): 0 99s ret: write_record(): 0 99s ret: write_record(): 0 99s ret: write_record(): 0 99s ============================================== 99s seq_reads_multi with aux: 99s type check reads: 99s r0 99s read_number 4019 99s r1 99s read_number 2287 99s r2 99s read_number 4019 99s r3 99s read_number 2287 99s r4 99s read_number 4019 99s r5 99s read_number 2287 99s 0a238451-b9ed-446d-a152-badd074006c4 99s read_number 4019 99s 0d624d4b-671f-40b8-9798-84f2ccc4d7fc 99s read_number 2287 99s ============================================== 99s get_reads_multi with aux: 99s type check reads: 99s r0 99s read_number 4019 99s r1 99s read_number 2287 99s r2 99s read_number 4019 99s r3 99s read_number 2287 99s r4 99s read_number 4019 99s r5 99s read_number 2287 99s 0a238451-b9ed-446d-a152-badd074006c4 99s read_number 4019 99s 0d624d4b-671f-40b8-9798-84f2ccc4d7fc 99s read_number 2287 99s ============================================== 99s write reads with aux multi 99s ret: write_header(): 0 99s ret: write_header(): 0 99s {'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)}} 99s {'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}} 99s ret: write_record(): 0 99s ============================================== 99s get all readIDs from index 99s ['r0', 'r1', 'r2', 'r3', 'r4', 'r5', '0a238451-b9ed-446d-a152-badd074006c4', '0d624d4b-671f-40b8-9798-84f2ccc4d7fc'] 99s number of reads: 8 99s ============================================== 99s done 99s 15-Nov-24 11:18:48 - [DEBUG]: pathname: examples/example.slow5 99s 15-Nov-24 11:18:48 - [DEBUG]: total_time_slow5_get_next: 0.0068721771240234375 seconds 99s 15-Nov-24 11:18:48 - [DEBUG]: total_time_yield_reads: 0.007285356521606445 seconds 99s 15-Nov-24 11:18:48 - [DEBUG]: total_single_write_time: 0.0 seconds 99s 15-Nov-24 11:18:48 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 99s 15-Nov-24 11:18:48 - [DEBUG]: total_multi_write_time: 0.0 seconds 99s 15-Nov-24 11:18:48 - [DEBUG]: pathname: examples/example2.slow5 99s 15-Nov-24 11:18:48 - [DEBUG]: total_time_slow5_get_next: 0.010813474655151367 seconds 99s 15-Nov-24 11:18:48 - [DEBUG]: total_time_yield_reads: 0.01240992546081543 seconds 99s 15-Nov-24 11:18:48 - [DEBUG]: total_single_write_time: 0.0 seconds 99s 15-Nov-24 11:18:48 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 99s 15-Nov-24 11:18:48 - [DEBUG]: total_multi_write_time: 0.0 seconds 99s 15-Nov-24 11:18:48 - [DEBUG]: examples/example_write_aux_multi.slow5 already closed 99s 15-Nov-24 11:18:48 - [DEBUG]: pathname: examples/example_write_aux_multi.slow5 99s 15-Nov-24 11:18:48 - [DEBUG]: total_time_slow5_get_next: 0.0 seconds 99s 15-Nov-24 11:18:48 - [DEBUG]: total_time_yield_reads: 0.0 seconds 99s 15-Nov-24 11:18:48 - [DEBUG]: total_single_write_time: 0.0 seconds 99s 15-Nov-24 11:18:48 - [DEBUG]: total_multi_write_signal_time: 0.019387006759643555 seconds 99s 15-Nov-24 11:18:48 - [DEBUG]: total_multi_write_time: 0.039360761642456055 seconds 99s 15-Nov-24 11:18:48 - [DEBUG]: pathname: examples/example2.slow5 99s 15-Nov-24 11:18:48 - [DEBUG]: total_time_slow5_get_next: 0.0 seconds 99s 15-Nov-24 11:18:48 - [DEBUG]: total_time_yield_reads: 0.0 seconds 99s 15-Nov-24 11:18:48 - [DEBUG]: total_single_write_time: 0.0 seconds 99s 15-Nov-24 11:18:48 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 99s 15-Nov-24 11:18:48 - [DEBUG]: total_multi_write_time: 0.0 seconds 99s 15-Nov-24 11:18:48 - [DEBUG]: examples/example_write_append_aux.blow5 already closed 99s 15-Nov-24 11:18:48 - [DEBUG]: pathname: examples/example_write_append_aux.blow5 99s 15-Nov-24 11:18:48 - [DEBUG]: total_time_slow5_get_next: 0.0 seconds 99s 15-Nov-24 11:18:48 - [DEBUG]: total_time_yield_reads: 0.0 seconds 99s 15-Nov-24 11:18:48 - [DEBUG]: total_single_write_time: 0.018673181533813477 seconds 99s 15-Nov-24 11:18:48 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 99s 15-Nov-24 11:18:48 - [DEBUG]: total_multi_write_time: 0.0 seconds 99s 15-Nov-24 11:18:48 - [DEBUG]: pathname: examples/example2.slow5 99s 15-Nov-24 11:18:48 - [DEBUG]: total_time_slow5_get_next: 0.0 seconds 99s 15-Nov-24 11:18:48 - [DEBUG]: total_time_yield_reads: 0.0 seconds 99s 15-Nov-24 11:18:48 - [DEBUG]: total_single_write_time: 0.0 seconds 99s 15-Nov-24 11:18:48 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 99s 15-Nov-24 11:18:48 - [DEBUG]: total_multi_write_time: 0.0 seconds 99s autopkgtest [11:18:49]: test run-pybinding-test: -----------------------] 99s autopkgtest [11:18:49]: test run-pybinding-test: - - - - - - - - - - results - - - - - - - - - - 99s run-pybinding-test PASS 100s autopkgtest [11:18:50]: test run-pkg-test: preparing testbed 171s autopkgtest [11:20:01]: testbed dpkg architecture: amd64 171s autopkgtest [11:20:01]: testbed apt version: 2.9.8 171s autopkgtest [11:20:01]: @@@@@@@@@@@@@@@@@@@@ test bed setup 172s Get:1 http://ftpmaster.internal/ubuntu plucky-proposed InRelease [73.9 kB] 173s Get:2 http://ftpmaster.internal/ubuntu plucky-proposed/universe Sources [1056 kB] 173s Get:3 http://ftpmaster.internal/ubuntu plucky-proposed/multiverse Sources [15.5 kB] 173s Get:4 http://ftpmaster.internal/ubuntu plucky-proposed/restricted Sources [7016 B] 173s Get:5 http://ftpmaster.internal/ubuntu plucky-proposed/main Sources [94.5 kB] 173s Get:6 http://ftpmaster.internal/ubuntu plucky-proposed/main amd64 Packages [176 kB] 173s Get:7 http://ftpmaster.internal/ubuntu plucky-proposed/main i386 Packages [109 kB] 173s Get:8 http://ftpmaster.internal/ubuntu plucky-proposed/restricted amd64 Packages [32.6 kB] 173s Get:9 http://ftpmaster.internal/ubuntu plucky-proposed/universe i386 Packages [297 kB] 173s Get:10 http://ftpmaster.internal/ubuntu plucky-proposed/universe amd64 Packages [833 kB] 173s Get:11 http://ftpmaster.internal/ubuntu plucky-proposed/multiverse amd64 Packages [9416 B] 173s Get:12 http://ftpmaster.internal/ubuntu plucky-proposed/multiverse i386 Packages [740 B] 173s Fetched 2704 kB in 1s (3412 kB/s) 173s Reading package lists... 176s Reading package lists... 176s Building dependency tree... 176s Reading state information... 176s Calculating upgrade... 176s The following packages will be upgraded: 176s firmware-sof-signed grub-common grub-pc grub-pc-bin grub2-common libcap-ng0 176s libexpat1 lxd-installer man-db pastebinit python3-systemd xfsprogs 177s 12 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 177s Need to get 13.6 MB of archives. 177s After this operation, 477 kB of additional disk space will be used. 177s Get:1 http://ftpmaster.internal/ubuntu plucky/main amd64 firmware-sof-signed all 2024.06-1ubuntu2 [7083 kB] 177s Get:2 http://ftpmaster.internal/ubuntu plucky/main amd64 libcap-ng0 amd64 0.8.5-3build1 [15.6 kB] 177s Get:3 http://ftpmaster.internal/ubuntu plucky/main amd64 libexpat1 amd64 2.6.4-1 [94.9 kB] 177s Get:4 http://ftpmaster.internal/ubuntu plucky/main amd64 man-db amd64 2.13.0-1 [1352 kB] 177s Get:5 http://ftpmaster.internal/ubuntu plucky/main amd64 grub2-common amd64 2.12-5ubuntu7 [672 kB] 177s Get:6 http://ftpmaster.internal/ubuntu plucky/main amd64 grub-pc amd64 2.12-5ubuntu7 [137 kB] 177s Get:7 http://ftpmaster.internal/ubuntu plucky/main amd64 grub-pc-bin amd64 2.12-5ubuntu7 [1127 kB] 177s Get:8 http://ftpmaster.internal/ubuntu plucky/main amd64 grub-common amd64 2.12-5ubuntu7 [2110 kB] 177s Get:9 http://ftpmaster.internal/ubuntu plucky/main amd64 lxd-installer all 9 [5084 B] 177s Get:10 http://ftpmaster.internal/ubuntu plucky/main amd64 pastebinit all 1.7.1-1 [14.9 kB] 177s Get:11 http://ftpmaster.internal/ubuntu plucky/main amd64 python3-systemd amd64 235-1build5 [45.7 kB] 177s Get:12 http://ftpmaster.internal/ubuntu plucky/main amd64 xfsprogs amd64 6.8.0-2.2ubuntu2 [926 kB] 178s Preconfiguring packages ... 178s Fetched 13.6 MB in 1s (13.3 MB/s) 178s (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 ... 75542 files and directories currently installed.) 178s Preparing to unpack .../firmware-sof-signed_2024.06-1ubuntu2_all.deb ... 178s Unpacking firmware-sof-signed (2024.06-1ubuntu2) over (2024.06-1ubuntu1) ... 178s Preparing to unpack .../libcap-ng0_0.8.5-3build1_amd64.deb ... 178s Unpacking libcap-ng0:amd64 (0.8.5-3build1) over (0.8.5-1) ... 178s Setting up libcap-ng0:amd64 (0.8.5-3build1) ... 178s (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 ... 75568 files and directories currently installed.) 178s Preparing to unpack .../0-libexpat1_2.6.4-1_amd64.deb ... 178s Unpacking libexpat1:amd64 (2.6.4-1) over (2.6.2-2) ... 178s Preparing to unpack .../1-man-db_2.13.0-1_amd64.deb ... 178s Unpacking man-db (2.13.0-1) over (2.12.1-3) ... 179s Preparing to unpack .../2-grub2-common_2.12-5ubuntu7_amd64.deb ... 179s Unpacking grub2-common (2.12-5ubuntu7) over (2.12-5ubuntu5.1) ... 179s Preparing to unpack .../3-grub-pc_2.12-5ubuntu7_amd64.deb ... 179s Unpacking grub-pc (2.12-5ubuntu7) over (2.12-5ubuntu5.1) ... 179s Preparing to unpack .../4-grub-pc-bin_2.12-5ubuntu7_amd64.deb ... 179s Unpacking grub-pc-bin (2.12-5ubuntu7) over (2.12-5ubuntu5.1) ... 179s Preparing to unpack .../5-grub-common_2.12-5ubuntu7_amd64.deb ... 179s Unpacking grub-common (2.12-5ubuntu7) over (2.12-5ubuntu5.1) ... 179s Preparing to unpack .../6-lxd-installer_9_all.deb ... 179s Unpacking lxd-installer (9) over (8) ... 179s Preparing to unpack .../7-pastebinit_1.7.1-1_all.deb ... 179s Unpacking pastebinit (1.7.1-1) over (1.7.0-1) ... 179s Preparing to unpack .../8-python3-systemd_235-1build5_amd64.deb ... 179s Unpacking python3-systemd (235-1build5) over (235-1build4) ... 179s Preparing to unpack .../9-xfsprogs_6.8.0-2.2ubuntu2_amd64.deb ... 179s Unpacking xfsprogs (6.8.0-2.2ubuntu2) over (6.8.0-2.2ubuntu1) ... 179s Setting up libexpat1:amd64 (2.6.4-1) ... 179s Setting up firmware-sof-signed (2024.06-1ubuntu2) ... 179s Setting up pastebinit (1.7.1-1) ... 179s Setting up man-db (2.13.0-1) ... 179s Updating database of manual pages ... 181s man-db.service is a disabled or a static unit not running, not starting it. 181s Setting up grub-common (2.12-5ubuntu7) ... 181s update-rc.d: warning: start and stop actions are no longer supported; falling back to defaults 182s Setting up xfsprogs (6.8.0-2.2ubuntu2) ... 182s update-initramfs: deferring update (trigger activated) 182s Setting up lxd-installer (9) ... 183s Setting up python3-systemd (235-1build5) ... 183s Setting up grub2-common (2.12-5ubuntu7) ... 183s Setting up grub-pc-bin (2.12-5ubuntu7) ... 183s Setting up grub-pc (2.12-5ubuntu7) ... 183s Installing for i386-pc platform. 183s Installation finished. No error reported. 183s Sourcing file `/etc/default/grub' 183s Sourcing file `/etc/default/grub.d/50-cloudimg-settings.cfg' 183s Sourcing file `/etc/default/grub.d/90-autopkgtest.cfg' 183s Generating grub configuration file ... 183s Found linux image: /boot/vmlinuz-6.11.0-8-generic 183s Found initrd image: /boot/initrd.img-6.11.0-8-generic 184s Warning: os-prober will not be executed to detect other bootable partitions. 184s Systems on them will not be added to the GRUB boot configuration. 184s Check GRUB_DISABLE_OS_PROBER documentation entry. 184s Adding boot menu entry for UEFI Firmware Settings ... 184s done 184s Processing triggers for libc-bin (2.40-1ubuntu3) ... 184s Processing triggers for install-info (7.1.1-1) ... 184s Processing triggers for initramfs-tools (0.142ubuntu34) ... 184s update-initramfs: Generating /boot/initrd.img-6.11.0-8-generic 184s W: No lz4 in /usr/bin:/sbin:/bin, using gzip 192s Reading package lists... 192s Building dependency tree... 192s Reading state information... 192s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 193s Hit:1 http://ftpmaster.internal/ubuntu plucky-proposed InRelease 193s Hit:2 http://ftpmaster.internal/ubuntu plucky InRelease 193s Hit:3 http://ftpmaster.internal/ubuntu plucky-updates InRelease 193s Hit:4 http://ftpmaster.internal/ubuntu plucky-security InRelease 194s Reading package lists... 194s Reading package lists... 194s Building dependency tree... 194s Reading state information... 194s Calculating upgrade... 194s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 194s Reading package lists... 195s Building dependency tree... 195s Reading state information... 195s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 195s autopkgtest [11:20:25]: rebooting testbed after setup commands that affected boot 199s autopkgtest-virt-ssh: WARNING: ssh connection failed. Retrying in 3 seconds... 216s Reading package lists... 217s Building dependency tree... 217s Reading state information... 217s Starting pkgProblemResolver with broken count: 0 217s Starting 2 pkgProblemResolver with broken count: 0 217s Done 217s The following additional packages will be installed: 217s build-essential cpp cpp-14 cpp-14-x86-64-linux-gnu cpp-x86-64-linux-gnu g++ 217s g++-14 g++-14-x86-64-linux-gnu g++-x86-64-linux-gnu gcc gcc-14 217s gcc-14-x86-64-linux-gnu gcc-x86-64-linux-gnu libasan8 libblas3 libcc1-0 217s libgcc-14-dev libgfortran5 libgomp1 libhwasan0 libisl23 libitm1 liblapack3 217s liblsan0 libmpc3 libquadmath0 libslow5-0t64 libslow5-dev libstdc++-14-dev 217s libstreamvbyte-dev libstreamvbyte0 libtsan2 libubsan1 python3-numpy 217s python3-slow5 zlib1g-dev 217s Suggested packages: 217s cpp-doc gcc-14-locales cpp-14-doc g++-multilib g++-14-multilib gcc-14-doc 217s gcc-multilib manpages-dev autoconf automake libtool flex bison gdb gcc-doc 217s gcc-14-multilib gdb-x86-64-linux-gnu libstdc++-14-doc gfortran 217s python-numpy-doc python3-dev python3-pytest 217s The following NEW packages will be installed: 217s autopkgtest-satdep build-essential cpp cpp-14 cpp-14-x86-64-linux-gnu 217s cpp-x86-64-linux-gnu g++ g++-14 g++-14-x86-64-linux-gnu g++-x86-64-linux-gnu 217s gcc gcc-14 gcc-14-x86-64-linux-gnu gcc-x86-64-linux-gnu libasan8 libblas3 217s libcc1-0 libgcc-14-dev libgfortran5 libgomp1 libhwasan0 libisl23 libitm1 217s liblapack3 liblsan0 libmpc3 libquadmath0 libslow5-0t64 libslow5-dev 217s libstdc++-14-dev libstreamvbyte-dev libstreamvbyte0 libtsan2 libubsan1 217s python3-numpy python3-slow5 zlib1g-dev 217s 0 upgraded, 37 newly installed, 0 to remove and 0 not upgraded. 217s Need to get 76.1 MB/76.1 MB of archives. 217s After this operation, 282 MB of additional disk space will be used. 217s Get:1 /tmp/autopkgtest.X6B0sV/2-autopkgtest-satdep.deb autopkgtest-satdep amd64 0 [760 B] 218s Get:2 http://ftpmaster.internal/ubuntu plucky/main amd64 libisl23 amd64 0.27-1 [685 kB] 218s Get:3 http://ftpmaster.internal/ubuntu plucky/main amd64 libmpc3 amd64 1.3.1-1build2 [55.3 kB] 218s Get:4 http://ftpmaster.internal/ubuntu plucky/main amd64 cpp-14-x86-64-linux-gnu amd64 14.2.0-8ubuntu1 [11.9 MB] 218s Get:5 http://ftpmaster.internal/ubuntu plucky/main amd64 cpp-14 amd64 14.2.0-8ubuntu1 [1030 B] 218s Get:6 http://ftpmaster.internal/ubuntu plucky/main amd64 cpp-x86-64-linux-gnu amd64 4:14.1.0-2ubuntu1 [5452 B] 218s Get:7 http://ftpmaster.internal/ubuntu plucky/main amd64 cpp amd64 4:14.1.0-2ubuntu1 [22.4 kB] 218s Get:8 http://ftpmaster.internal/ubuntu plucky/main amd64 libcc1-0 amd64 14.2.0-8ubuntu1 [47.6 kB] 218s Get:9 http://ftpmaster.internal/ubuntu plucky/main amd64 libgomp1 amd64 14.2.0-8ubuntu1 [148 kB] 218s Get:10 http://ftpmaster.internal/ubuntu plucky/main amd64 libitm1 amd64 14.2.0-8ubuntu1 [29.1 kB] 218s Get:11 http://ftpmaster.internal/ubuntu plucky/main amd64 libasan8 amd64 14.2.0-8ubuntu1 [2998 kB] 219s Get:12 http://ftpmaster.internal/ubuntu plucky/main amd64 liblsan0 amd64 14.2.0-8ubuntu1 [1317 kB] 219s Get:13 http://ftpmaster.internal/ubuntu plucky/main amd64 libtsan2 amd64 14.2.0-8ubuntu1 [2732 kB] 219s Get:14 http://ftpmaster.internal/ubuntu plucky/main amd64 libubsan1 amd64 14.2.0-8ubuntu1 [1177 kB] 219s Get:15 http://ftpmaster.internal/ubuntu plucky/main amd64 libhwasan0 amd64 14.2.0-8ubuntu1 [1634 kB] 219s Get:16 http://ftpmaster.internal/ubuntu plucky/main amd64 libquadmath0 amd64 14.2.0-8ubuntu1 [153 kB] 219s Get:17 http://ftpmaster.internal/ubuntu plucky/main amd64 libgcc-14-dev amd64 14.2.0-8ubuntu1 [2814 kB] 219s Get:18 http://ftpmaster.internal/ubuntu plucky/main amd64 gcc-14-x86-64-linux-gnu amd64 14.2.0-8ubuntu1 [23.3 MB] 219s Get:19 http://ftpmaster.internal/ubuntu plucky/main amd64 gcc-14 amd64 14.2.0-8ubuntu1 [528 kB] 219s Get:20 http://ftpmaster.internal/ubuntu plucky/main amd64 gcc-x86-64-linux-gnu amd64 4:14.1.0-2ubuntu1 [1214 B] 219s Get:21 http://ftpmaster.internal/ubuntu plucky/main amd64 gcc amd64 4:14.1.0-2ubuntu1 [5000 B] 219s Get:22 http://ftpmaster.internal/ubuntu plucky/main amd64 libstdc++-14-dev amd64 14.2.0-8ubuntu1 [2504 kB] 219s Get:23 http://ftpmaster.internal/ubuntu plucky/main amd64 g++-14-x86-64-linux-gnu amd64 14.2.0-8ubuntu1 [13.3 MB] 220s Get:24 http://ftpmaster.internal/ubuntu plucky/main amd64 g++-14 amd64 14.2.0-8ubuntu1 [19.9 kB] 220s Get:25 http://ftpmaster.internal/ubuntu plucky/main amd64 g++-x86-64-linux-gnu amd64 4:14.1.0-2ubuntu1 [966 B] 220s Get:26 http://ftpmaster.internal/ubuntu plucky/main amd64 g++ amd64 4:14.1.0-2ubuntu1 [1100 B] 220s Get:27 http://ftpmaster.internal/ubuntu plucky/main amd64 build-essential amd64 12.10ubuntu1 [4928 B] 220s Get:28 http://ftpmaster.internal/ubuntu plucky/main amd64 libblas3 amd64 3.12.0-3build2 [247 kB] 220s Get:29 http://ftpmaster.internal/ubuntu plucky/main amd64 libgfortran5 amd64 14.2.0-8ubuntu1 [909 kB] 220s Get:30 http://ftpmaster.internal/ubuntu plucky/main amd64 liblapack3 amd64 3.12.0-3build2 [2668 kB] 220s Get:31 http://ftpmaster.internal/ubuntu plucky/universe amd64 libslow5-0t64 amd64 0.7.0+dfsg-3 [69.1 kB] 220s Get:32 http://ftpmaster.internal/ubuntu plucky/universe amd64 libslow5-dev amd64 0.7.0+dfsg-3 [84.3 kB] 220s Get:33 http://ftpmaster.internal/ubuntu plucky/universe amd64 libstreamvbyte0 amd64 0.4.1-4ubuntu1 [6244 B] 220s Get:34 http://ftpmaster.internal/ubuntu plucky/universe amd64 libstreamvbyte-dev amd64 0.4.1-4ubuntu1 [6460 B] 220s Get:35 http://ftpmaster.internal/ubuntu plucky-proposed/main amd64 python3-numpy amd64 1:1.26.4+ds-11ubuntu1 [5319 kB] 220s Get:36 http://ftpmaster.internal/ubuntu plucky/universe amd64 python3-slow5 amd64 0.7.0+dfsg-3 [482 kB] 220s Get:37 http://ftpmaster.internal/ubuntu plucky/main amd64 zlib1g-dev amd64 1:1.3.dfsg+really1.3.1-1ubuntu1 [895 kB] 220s Fetched 76.1 MB in 3s (25.8 MB/s) 220s Selecting previously unselected package libisl23:amd64. 221s (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 ... 75575 files and directories currently installed.) 221s Preparing to unpack .../00-libisl23_0.27-1_amd64.deb ... 221s Unpacking libisl23:amd64 (0.27-1) ... 221s Selecting previously unselected package libmpc3:amd64. 221s Preparing to unpack .../01-libmpc3_1.3.1-1build2_amd64.deb ... 221s Unpacking libmpc3:amd64 (1.3.1-1build2) ... 221s Selecting previously unselected package cpp-14-x86-64-linux-gnu. 221s Preparing to unpack .../02-cpp-14-x86-64-linux-gnu_14.2.0-8ubuntu1_amd64.deb ... 221s Unpacking cpp-14-x86-64-linux-gnu (14.2.0-8ubuntu1) ... 221s Selecting previously unselected package cpp-14. 221s Preparing to unpack .../03-cpp-14_14.2.0-8ubuntu1_amd64.deb ... 221s Unpacking cpp-14 (14.2.0-8ubuntu1) ... 221s Selecting previously unselected package cpp-x86-64-linux-gnu. 221s Preparing to unpack .../04-cpp-x86-64-linux-gnu_4%3a14.1.0-2ubuntu1_amd64.deb ... 221s Unpacking cpp-x86-64-linux-gnu (4:14.1.0-2ubuntu1) ... 221s Selecting previously unselected package cpp. 221s Preparing to unpack .../05-cpp_4%3a14.1.0-2ubuntu1_amd64.deb ... 221s Unpacking cpp (4:14.1.0-2ubuntu1) ... 221s Selecting previously unselected package libcc1-0:amd64. 221s Preparing to unpack .../06-libcc1-0_14.2.0-8ubuntu1_amd64.deb ... 221s Unpacking libcc1-0:amd64 (14.2.0-8ubuntu1) ... 221s Selecting previously unselected package libgomp1:amd64. 221s Preparing to unpack .../07-libgomp1_14.2.0-8ubuntu1_amd64.deb ... 221s Unpacking libgomp1:amd64 (14.2.0-8ubuntu1) ... 221s Selecting previously unselected package libitm1:amd64. 221s Preparing to unpack .../08-libitm1_14.2.0-8ubuntu1_amd64.deb ... 221s Unpacking libitm1:amd64 (14.2.0-8ubuntu1) ... 221s Selecting previously unselected package libasan8:amd64. 221s Preparing to unpack .../09-libasan8_14.2.0-8ubuntu1_amd64.deb ... 221s Unpacking libasan8:amd64 (14.2.0-8ubuntu1) ... 221s Selecting previously unselected package liblsan0:amd64. 221s Preparing to unpack .../10-liblsan0_14.2.0-8ubuntu1_amd64.deb ... 221s Unpacking liblsan0:amd64 (14.2.0-8ubuntu1) ... 221s Selecting previously unselected package libtsan2:amd64. 221s Preparing to unpack .../11-libtsan2_14.2.0-8ubuntu1_amd64.deb ... 221s Unpacking libtsan2:amd64 (14.2.0-8ubuntu1) ... 221s Selecting previously unselected package libubsan1:amd64. 221s Preparing to unpack .../12-libubsan1_14.2.0-8ubuntu1_amd64.deb ... 221s Unpacking libubsan1:amd64 (14.2.0-8ubuntu1) ... 221s Selecting previously unselected package libhwasan0:amd64. 221s Preparing to unpack .../13-libhwasan0_14.2.0-8ubuntu1_amd64.deb ... 221s Unpacking libhwasan0:amd64 (14.2.0-8ubuntu1) ... 221s Selecting previously unselected package libquadmath0:amd64. 221s Preparing to unpack .../14-libquadmath0_14.2.0-8ubuntu1_amd64.deb ... 221s Unpacking libquadmath0:amd64 (14.2.0-8ubuntu1) ... 221s Selecting previously unselected package libgcc-14-dev:amd64. 221s Preparing to unpack .../15-libgcc-14-dev_14.2.0-8ubuntu1_amd64.deb ... 221s Unpacking libgcc-14-dev:amd64 (14.2.0-8ubuntu1) ... 221s Selecting previously unselected package gcc-14-x86-64-linux-gnu. 221s Preparing to unpack .../16-gcc-14-x86-64-linux-gnu_14.2.0-8ubuntu1_amd64.deb ... 221s Unpacking gcc-14-x86-64-linux-gnu (14.2.0-8ubuntu1) ... 222s Selecting previously unselected package gcc-14. 222s Preparing to unpack .../17-gcc-14_14.2.0-8ubuntu1_amd64.deb ... 222s Unpacking gcc-14 (14.2.0-8ubuntu1) ... 222s Selecting previously unselected package gcc-x86-64-linux-gnu. 222s Preparing to unpack .../18-gcc-x86-64-linux-gnu_4%3a14.1.0-2ubuntu1_amd64.deb ... 222s Unpacking gcc-x86-64-linux-gnu (4:14.1.0-2ubuntu1) ... 222s Selecting previously unselected package gcc. 222s Preparing to unpack .../19-gcc_4%3a14.1.0-2ubuntu1_amd64.deb ... 222s Unpacking gcc (4:14.1.0-2ubuntu1) ... 222s Selecting previously unselected package libstdc++-14-dev:amd64. 222s Preparing to unpack .../20-libstdc++-14-dev_14.2.0-8ubuntu1_amd64.deb ... 222s Unpacking libstdc++-14-dev:amd64 (14.2.0-8ubuntu1) ... 222s Selecting previously unselected package g++-14-x86-64-linux-gnu. 222s Preparing to unpack .../21-g++-14-x86-64-linux-gnu_14.2.0-8ubuntu1_amd64.deb ... 222s Unpacking g++-14-x86-64-linux-gnu (14.2.0-8ubuntu1) ... 222s Selecting previously unselected package g++-14. 222s Preparing to unpack .../22-g++-14_14.2.0-8ubuntu1_amd64.deb ... 222s Unpacking g++-14 (14.2.0-8ubuntu1) ... 222s Selecting previously unselected package g++-x86-64-linux-gnu. 222s Preparing to unpack .../23-g++-x86-64-linux-gnu_4%3a14.1.0-2ubuntu1_amd64.deb ... 222s Unpacking g++-x86-64-linux-gnu (4:14.1.0-2ubuntu1) ... 222s Selecting previously unselected package g++. 222s Preparing to unpack .../24-g++_4%3a14.1.0-2ubuntu1_amd64.deb ... 222s Unpacking g++ (4:14.1.0-2ubuntu1) ... 222s Selecting previously unselected package build-essential. 222s Preparing to unpack .../25-build-essential_12.10ubuntu1_amd64.deb ... 222s Unpacking build-essential (12.10ubuntu1) ... 222s Selecting previously unselected package libblas3:amd64. 222s Preparing to unpack .../26-libblas3_3.12.0-3build2_amd64.deb ... 222s Unpacking libblas3:amd64 (3.12.0-3build2) ... 222s Selecting previously unselected package libgfortran5:amd64. 222s Preparing to unpack .../27-libgfortran5_14.2.0-8ubuntu1_amd64.deb ... 222s Unpacking libgfortran5:amd64 (14.2.0-8ubuntu1) ... 222s Selecting previously unselected package liblapack3:amd64. 222s Preparing to unpack .../28-liblapack3_3.12.0-3build2_amd64.deb ... 222s Unpacking liblapack3:amd64 (3.12.0-3build2) ... 222s Selecting previously unselected package libslow5-0t64:amd64. 222s Preparing to unpack .../29-libslow5-0t64_0.7.0+dfsg-3_amd64.deb ... 222s Unpacking libslow5-0t64:amd64 (0.7.0+dfsg-3) ... 222s Selecting previously unselected package libslow5-dev:amd64. 222s Preparing to unpack .../30-libslow5-dev_0.7.0+dfsg-3_amd64.deb ... 222s Unpacking libslow5-dev:amd64 (0.7.0+dfsg-3) ... 222s Selecting previously unselected package libstreamvbyte0:amd64. 222s Preparing to unpack .../31-libstreamvbyte0_0.4.1-4ubuntu1_amd64.deb ... 222s Unpacking libstreamvbyte0:amd64 (0.4.1-4ubuntu1) ... 222s Selecting previously unselected package libstreamvbyte-dev:amd64. 222s Preparing to unpack .../32-libstreamvbyte-dev_0.4.1-4ubuntu1_amd64.deb ... 222s Unpacking libstreamvbyte-dev:amd64 (0.4.1-4ubuntu1) ... 222s Selecting previously unselected package python3-numpy. 222s Preparing to unpack .../33-python3-numpy_1%3a1.26.4+ds-11ubuntu1_amd64.deb ... 222s Unpacking python3-numpy (1:1.26.4+ds-11ubuntu1) ... 222s Selecting previously unselected package python3-slow5. 222s Preparing to unpack .../34-python3-slow5_0.7.0+dfsg-3_amd64.deb ... 222s Unpacking python3-slow5 (0.7.0+dfsg-3) ... 223s Selecting previously unselected package zlib1g-dev:amd64. 223s Preparing to unpack .../35-zlib1g-dev_1%3a1.3.dfsg+really1.3.1-1ubuntu1_amd64.deb ... 223s Unpacking zlib1g-dev:amd64 (1:1.3.dfsg+really1.3.1-1ubuntu1) ... 223s Selecting previously unselected package autopkgtest-satdep. 223s Preparing to unpack .../36-2-autopkgtest-satdep.deb ... 223s Unpacking autopkgtest-satdep (0) ... 223s Setting up libstreamvbyte0:amd64 (0.4.1-4ubuntu1) ... 223s Setting up libgomp1:amd64 (14.2.0-8ubuntu1) ... 223s Setting up libblas3:amd64 (3.12.0-3build2) ... 223s update-alternatives: using /usr/lib/x86_64-linux-gnu/blas/libblas.so.3 to provide /usr/lib/x86_64-linux-gnu/libblas.so.3 (libblas.so.3-x86_64-linux-gnu) in auto mode 223s Setting up libstreamvbyte-dev:amd64 (0.4.1-4ubuntu1) ... 223s Setting up libquadmath0:amd64 (14.2.0-8ubuntu1) ... 223s Setting up libmpc3:amd64 (1.3.1-1build2) ... 223s Setting up libslow5-0t64:amd64 (0.7.0+dfsg-3) ... 223s Setting up libgfortran5:amd64 (14.2.0-8ubuntu1) ... 223s Setting up libubsan1:amd64 (14.2.0-8ubuntu1) ... 223s Setting up zlib1g-dev:amd64 (1:1.3.dfsg+really1.3.1-1ubuntu1) ... 223s Setting up libhwasan0:amd64 (14.2.0-8ubuntu1) ... 223s Setting up libasan8:amd64 (14.2.0-8ubuntu1) ... 223s Setting up libtsan2:amd64 (14.2.0-8ubuntu1) ... 223s Setting up libisl23:amd64 (0.27-1) ... 223s Setting up libcc1-0:amd64 (14.2.0-8ubuntu1) ... 223s Setting up liblsan0:amd64 (14.2.0-8ubuntu1) ... 223s Setting up libitm1:amd64 (14.2.0-8ubuntu1) ... 223s Setting up liblapack3:amd64 (3.12.0-3build2) ... 223s update-alternatives: using /usr/lib/x86_64-linux-gnu/lapack/liblapack.so.3 to provide /usr/lib/x86_64-linux-gnu/liblapack.so.3 (liblapack.so.3-x86_64-linux-gnu) in auto mode 223s Setting up libslow5-dev:amd64 (0.7.0+dfsg-3) ... 223s Setting up cpp-14-x86-64-linux-gnu (14.2.0-8ubuntu1) ... 223s Setting up python3-numpy (1:1.26.4+ds-11ubuntu1) ... 224s Setting up cpp-14 (14.2.0-8ubuntu1) ... 224s Setting up libgcc-14-dev:amd64 (14.2.0-8ubuntu1) ... 224s Setting up libstdc++-14-dev:amd64 (14.2.0-8ubuntu1) ... 224s Setting up cpp-x86-64-linux-gnu (4:14.1.0-2ubuntu1) ... 224s Setting up python3-slow5 (0.7.0+dfsg-3) ... 224s Setting up cpp (4:14.1.0-2ubuntu1) ... 224s Setting up gcc-14-x86-64-linux-gnu (14.2.0-8ubuntu1) ... 224s Setting up gcc-x86-64-linux-gnu (4:14.1.0-2ubuntu1) ... 224s Setting up gcc-14 (14.2.0-8ubuntu1) ... 224s Setting up g++-14-x86-64-linux-gnu (14.2.0-8ubuntu1) ... 224s Setting up g++-x86-64-linux-gnu (4:14.1.0-2ubuntu1) ... 224s Setting up g++-14 (14.2.0-8ubuntu1) ... 224s Setting up gcc (4:14.1.0-2ubuntu1) ... 224s Setting up g++ (4:14.1.0-2ubuntu1) ... 224s update-alternatives: using /usr/bin/g++ to provide /usr/bin/c++ (c++) in auto mode 224s Setting up build-essential (12.10ubuntu1) ... 224s Setting up autopkgtest-satdep (0) ... 224s Processing triggers for man-db (2.13.0-1) ... 225s Processing triggers for libc-bin (2.40-1ubuntu3) ... 227s (Reading database ... 77831 files and directories currently installed.) 227s Removing autopkgtest-satdep (0) ... 230s autopkgtest [11:21:00]: test run-pkg-test: [----------------------- 230s Checking unit_test_ascii.c 230s Done! 230s Checking unit_test_binary.c 230s Done! 230s Checking unit_test_empty.c 231s Done! 231s Checking unit_test_enum.c 231s Done! 231s Checking unit_test_helpers.c 231s Done! 231s Checking unit_test_lossless.c 231s Done! 231s Checking unit_test_press.c 231s Done! 231s Checking unit_test_two_rg.c 231s Done! 231s autopkgtest [11:21:01]: test run-pkg-test: -----------------------] 232s run-pkg-test PASS 232s autopkgtest [11:21:02]: test run-pkg-test: - - - - - - - - - - results - - - - - - - - - - 232s autopkgtest [11:21:02]: @@@@@@@@@@@@@@@@@@@@ summary 232s run-pybinding-test PASS 232s run-pkg-test PASS 244s virt: nova [W] Skipping flock for amd64 244s virt: Creating nova instance adt-plucky-amd64-libslow5lib-20241115-111709-juju-7f2275-prod-proposed-migration-environment-2-ca7a796c-12d9-4d9f-bc2f-52e720aaf9b2 from image adt/ubuntu-plucky-amd64-server-20241114.img (UUID 79d80331-8736-463c-82c6-8c9e13c0a4ca)... 244s virt: nova [W] Skipping flock for amd64 244s virt: Creating nova instance adt-plucky-amd64-libslow5lib-20241115-111709-juju-7f2275-prod-proposed-migration-environment-2-ca7a796c-12d9-4d9f-bc2f-52e720aaf9b2 from image adt/ubuntu-plucky-amd64-server-20241114.img (UUID 79d80331-8736-463c-82c6-8c9e13c0a4ca)...