1s autopkgtest [15:30:40]: starting date: 2024-03-05
  1s autopkgtest [15:30:40]: git checkout: d9c0295 adt_testbed.py: supress warnings from apt using a shell pipeline
  1s autopkgtest [15:30:40]: host juju-7f2275-prod-proposed-migration-environment-3; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.h7qfakoz/out --timeout-copy=6000 --setup-commands /home/ubuntu/autopkgtest-cloud/worker-config-production/setup-canonical.sh --setup-commands /home/ubuntu/autopkgtest/setup-commands/setup-testbed --apt-pocket=proposed=src:zlib --apt-upgrade libslow5lib --timeout-short=300 --timeout-copy=20000 --timeout-build=20000 --env=ADT_TEST_TRIGGERS=zlib/1:1.3.dfsg-3.1ubuntu1 -- ssh -s /home/ubuntu/autopkgtest/ssh-setup/nova -- --flavor autopkgtest --security-groups autopkgtest-juju-7f2275-prod-proposed-migration-environment-3@bos03-arm64-25.secgroup --name adt-noble-arm64-libslow5lib-20240305-153039-juju-7f2275-prod-proposed-migration-environment-3 --image adt/ubuntu-noble-arm64-server --keyname testbed-juju-7f2275-prod-proposed-migration-environment-3 --net-id=net_prod-proposed-migration -e TERM=linux -e ''"'"'http_proxy=http://squid.internal:3128'"'"'' -e ''"'"'https_proxy=http://squid.internal:3128'"'"'' -e ''"'"'no_proxy=127.0.0.1,127.0.1.1,login.ubuntu.com,localhost,localdomain,novalocal,internal,archive.ubuntu.com,ports.ubuntu.com,security.ubuntu.com,ddebs.ubuntu.com,changelogs.ubuntu.com,launchpadlibrarian.net,launchpadcontent.net,launchpad.net,10.24.0.0/24,keystone.ps5.canonical.com,objectstorage.prodstack5.canonical.com'"'"'' --mirror=http://ftpmaster.internal/ubuntu/
 69s autopkgtest [15:31:48]: @@@@@@@@@@@@@@@@@@@@ test bed setup
 69s Get:1 http://ftpmaster.internal/ubuntu noble-proposed InRelease [117 kB]
 70s Get:2 http://ftpmaster.internal/ubuntu noble-proposed/multiverse Sources [24.5 kB]
 70s Get:3 http://ftpmaster.internal/ubuntu noble-proposed/restricted Sources [3976 B]
 70s Get:4 http://ftpmaster.internal/ubuntu noble-proposed/main Sources [322 kB]
 70s Get:5 http://ftpmaster.internal/ubuntu noble-proposed/universe Sources [1807 kB]
 70s Get:6 http://ftpmaster.internal/ubuntu noble-proposed/main arm64 Packages [427 kB]
 70s Get:7 http://ftpmaster.internal/ubuntu noble-proposed/main arm64 c-n-f Metadata [3144 B]
 70s Get:8 http://ftpmaster.internal/ubuntu noble-proposed/restricted arm64 Packages [20.3 kB]
 70s Get:9 http://ftpmaster.internal/ubuntu noble-proposed/restricted arm64 c-n-f Metadata [116 B]
 70s Get:10 http://ftpmaster.internal/ubuntu noble-proposed/universe arm64 Packages [2077 kB]
 70s Get:11 http://ftpmaster.internal/ubuntu noble-proposed/universe arm64 c-n-f Metadata [8528 B]
 70s Get:12 http://ftpmaster.internal/ubuntu noble-proposed/multiverse arm64 Packages [14.3 kB]
 70s Get:13 http://ftpmaster.internal/ubuntu noble-proposed/multiverse arm64 c-n-f Metadata [116 B]
 71s Fetched 4824 kB in 1s (3649 kB/s)
 72s Reading package lists...
 74s Reading package lists...
 74s Building dependency tree...
 74s Reading state information...
 75s Calculating upgrade...
 75s The following packages will be upgraded:
 75s   zlib1g
 75s 1 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.
 75s Need to get 61.7 kB of archives.
 75s After this operation, 0 B of additional disk space will be used.
 75s Get:1 http://ftpmaster.internal/ubuntu noble-proposed/main arm64 zlib1g arm64 1:1.3.dfsg-3.1ubuntu1 [61.7 kB]
 76s Fetched 61.7 kB in 0s (194 kB/s)
 76s (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 ... 74660 files and directories currently installed.)
 76s Preparing to unpack .../zlib1g_1%3a1.3.dfsg-3.1ubuntu1_arm64.deb ...
 76s Unpacking zlib1g:arm64 (1:1.3.dfsg-3.1ubuntu1) over (1:1.3.dfsg-3ubuntu1) ...
 76s Setting up zlib1g:arm64 (1:1.3.dfsg-3.1ubuntu1) ...
 76s Processing triggers for libc-bin (2.39-0ubuntu2) ...
 76s Reading package lists...
 77s Building dependency tree...
 77s Reading state information...
 77s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.
 78s sh: Attempting to set up Debian/Ubuntu apt sources automatically
 78s sh: Distribution appears to be Ubuntu
 79s Reading package lists...
 79s Building dependency tree...
 79s Reading state information...
 79s eatmydata is already the newest version (131-1).
 79s dbus is already the newest version (1.14.10-4ubuntu1).
 79s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.
 80s Reading package lists...
 80s Building dependency tree...
 80s Reading state information...
 80s rng-tools-debian is already the newest version (2.4).
 80s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.
 80s Reading package lists...
 81s Building dependency tree...
 81s Reading state information...
 81s haveged is already the newest version (1.9.14-1ubuntu1).
 81s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.
 81s Reading package lists...
 81s Building dependency tree...
 81s Reading state information...
 82s The following packages will be REMOVED:
 82s   cloud-init* python3-configobj* python3-debconf*
 82s 0 upgraded, 0 newly installed, 3 to remove and 0 not upgraded.
 82s After this operation, 3248 kB disk space will be freed.
 82s (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 ... 74660 files and directories currently installed.)
 82s Removing cloud-init (24.1-0ubuntu1) ...
 83s Removing python3-configobj (5.0.8-3) ...
 83s Removing python3-debconf (1.5.86) ...
 83s Processing triggers for man-db (2.12.0-3) ...
 84s (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 ... 74271 files and directories currently installed.)
 84s Purging configuration files for cloud-init (24.1-0ubuntu1) ...
 84s dpkg: warning: while removing cloud-init, directory '/etc/cloud/cloud.cfg.d' not empty so not removed
 84s Processing triggers for rsyslog (8.2312.0-3ubuntu3) ...
 85s Reading package lists...
 85s Building dependency tree...
 85s Reading state information...
 86s linux-generic is already the newest version (6.8.0-11.11+1).
 86s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.
 86s Hit:1 http://ftpmaster.internal/ubuntu noble InRelease
 86s Hit:2 http://ftpmaster.internal/ubuntu noble-updates InRelease
 86s Hit:3 http://ftpmaster.internal/ubuntu noble-security InRelease
 86s Hit:4 http://ftpmaster.internal/ubuntu noble-proposed InRelease
 88s Reading package lists...
 88s Reading package lists...
 89s Building dependency tree...
 89s Reading state information...
 89s Calculating upgrade...
 89s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.
 89s Reading package lists...
 90s Building dependency tree...
 90s Reading state information...
 90s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.
 91s autopkgtest [15:32:10]: rebooting testbed after setup commands that affected boot
117s autopkgtest [15:32:36]: testbed running kernel: Linux 6.8.0-11-generic #11-Ubuntu SMP PREEMPT_DYNAMIC Wed Feb 14 02:53:31 UTC 2024
122s autopkgtest [15:32:41]: testbed dpkg architecture: arm64
124s autopkgtest [15:32:43]: @@@@@@@@@@@@@@@@@@@@ apt-source libslow5lib
127s Get:1 http://ftpmaster.internal/ubuntu noble/universe libslow5lib 0.7.0+dfsg-2ubuntu4 (dsc) [2580 B]
127s Get:2 http://ftpmaster.internal/ubuntu noble/universe libslow5lib 0.7.0+dfsg-2ubuntu4 (tar) [2014 kB]
127s Get:3 http://ftpmaster.internal/ubuntu noble/universe libslow5lib 0.7.0+dfsg-2ubuntu4 (diff) [8240 B]
128s gpgv: Signature made Tue Nov 14 20:48:17 2023 UTC
128s gpgv:                using RSA key 25E3FF2D7F469DBE7D0D4E50AFCFEC8E669CE1C2
128s gpgv: Can't check signature: No public key
128s dpkg-source: warning: cannot verify inline signature for ./libslow5lib_0.7.0+dfsg-2ubuntu4.dsc: no acceptable signature found
128s autopkgtest [15:32:47]: testing package libslow5lib version 0.7.0+dfsg-2ubuntu4
128s autopkgtest [15:32:47]: build not needed
137s autopkgtest [15:32:56]: test run-pybinding-test: preparing testbed
140s Reading package lists...
141s Building dependency tree...
141s Reading state information...
141s Correcting dependencies...Starting pkgProblemResolver with broken count: 0
141s Starting 2 pkgProblemResolver with broken count: 0
141s Done
141s  Done
142s Starting pkgProblemResolver with broken count: 0
142s Starting 2 pkgProblemResolver with broken count: 0
142s Done
142s The following additional packages will be installed:
142s   libblas3 libgfortran5 liblapack3 libpython3.11-minimal libpython3.11-stdlib
142s   libslow5-0 libslow5-dev libstreamvbyte0 python3-all python3-distutils
142s   python3-lib2to3 python3-numpy python3-slow5 python3.11 python3.11-minimal
142s Suggested packages:
142s   gcc gfortran python3-dev python3-pytest python3.11-venv python3.11-doc
142s   binfmt-support
142s The following NEW packages will be installed:
142s   libblas3 libgfortran5 liblapack3 libpython3.11-minimal libpython3.11-stdlib
142s   libslow5-0 libslow5-dev libstreamvbyte0 python3-all python3-distutils
142s   python3-lib2to3 python3-numpy python3-slow5 python3.11 python3.11-minimal
143s 0 upgraded, 15 newly installed, 0 to remove and 0 not upgraded.
143s 1 not fully installed or removed.
143s Need to get 13.8 MB of archives.
143s After this operation, 68.5 MB of additional disk space will be used.
143s Get:1 http://ftpmaster.internal/ubuntu noble/universe arm64 libslow5-0 arm64 0.7.0+dfsg-2ubuntu4 [61.3 kB]
143s Get:2 http://ftpmaster.internal/ubuntu noble/universe arm64 libslow5-dev arm64 0.7.0+dfsg-2ubuntu4 [90.0 kB]
143s Get:3 http://ftpmaster.internal/ubuntu noble/universe arm64 libstreamvbyte0 arm64 0.4.1-4ubuntu1 [6260 B]
143s Get:4 http://ftpmaster.internal/ubuntu noble/main arm64 libpython3.11-minimal arm64 3.11.8-1 [837 kB]
143s Get:5 http://ftpmaster.internal/ubuntu noble/main arm64 python3.11-minimal arm64 3.11.8-1 [2150 kB]
143s Get:6 http://ftpmaster.internal/ubuntu noble/main arm64 libpython3.11-stdlib arm64 3.11.8-1 [1913 kB]
143s Get:7 http://ftpmaster.internal/ubuntu noble/main arm64 python3.11 arm64 3.11.8-1 [589 kB]
143s Get:8 http://ftpmaster.internal/ubuntu noble/main arm64 libblas3 arm64 3.12.0-3 [143 kB]
143s Get:9 http://ftpmaster.internal/ubuntu noble/main arm64 libgfortran5 arm64 14-20240221-2.1ubuntu1 [443 kB]
143s Get:10 http://ftpmaster.internal/ubuntu noble/main arm64 liblapack3 arm64 3.12.0-3 [2241 kB]
143s Get:11 http://ftpmaster.internal/ubuntu noble/main arm64 python3-numpy arm64 1:1.24.2-2 [4525 kB]
143s Get:12 http://ftpmaster.internal/ubuntu noble/universe arm64 python3-slow5 arm64 0.7.0+dfsg-2ubuntu4 [610 kB]
143s Get:13 http://ftpmaster.internal/ubuntu noble/main arm64 python3-lib2to3 all 3.11.5-1 [79.0 kB]
143s Get:14 http://ftpmaster.internal/ubuntu noble/main arm64 python3-distutils all 3.11.5-1 [131 kB]
143s Get:15 http://ftpmaster.internal/ubuntu noble/main arm64 python3-all arm64 3.12.1-0ubuntu2 [906 B]
144s Fetched 13.8 MB in 1s (12.6 MB/s)
144s Selecting previously unselected package libslow5-0:arm64.
144s (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 ... 74216 files and directories currently installed.)
144s Preparing to unpack .../00-libslow5-0_0.7.0+dfsg-2ubuntu4_arm64.deb ...
144s Unpacking libslow5-0:arm64 (0.7.0+dfsg-2ubuntu4) ...
144s Selecting previously unselected package libslow5-dev:arm64.
144s Preparing to unpack .../01-libslow5-dev_0.7.0+dfsg-2ubuntu4_arm64.deb ...
144s Unpacking libslow5-dev:arm64 (0.7.0+dfsg-2ubuntu4) ...
144s Selecting previously unselected package libstreamvbyte0:arm64.
144s Preparing to unpack .../02-libstreamvbyte0_0.4.1-4ubuntu1_arm64.deb ...
144s Unpacking libstreamvbyte0:arm64 (0.4.1-4ubuntu1) ...
144s Selecting previously unselected package libpython3.11-minimal:arm64.
144s Preparing to unpack .../03-libpython3.11-minimal_3.11.8-1_arm64.deb ...
144s Unpacking libpython3.11-minimal:arm64 (3.11.8-1) ...
144s Selecting previously unselected package python3.11-minimal.
144s Preparing to unpack .../04-python3.11-minimal_3.11.8-1_arm64.deb ...
144s Unpacking python3.11-minimal (3.11.8-1) ...
144s Selecting previously unselected package libpython3.11-stdlib:arm64.
145s Preparing to unpack .../05-libpython3.11-stdlib_3.11.8-1_arm64.deb ...
145s Unpacking libpython3.11-stdlib:arm64 (3.11.8-1) ...
145s Selecting previously unselected package python3.11.
145s Preparing to unpack .../06-python3.11_3.11.8-1_arm64.deb ...
145s Unpacking python3.11 (3.11.8-1) ...
145s Selecting previously unselected package libblas3:arm64.
145s Preparing to unpack .../07-libblas3_3.12.0-3_arm64.deb ...
145s Unpacking libblas3:arm64 (3.12.0-3) ...
145s Selecting previously unselected package libgfortran5:arm64.
145s Preparing to unpack .../08-libgfortran5_14-20240221-2.1ubuntu1_arm64.deb ...
145s Unpacking libgfortran5:arm64 (14-20240221-2.1ubuntu1) ...
145s Selecting previously unselected package liblapack3:arm64.
145s Preparing to unpack .../09-liblapack3_3.12.0-3_arm64.deb ...
145s Unpacking liblapack3:arm64 (3.12.0-3) ...
145s Selecting previously unselected package python3-numpy.
145s Preparing to unpack .../10-python3-numpy_1%3a1.24.2-2_arm64.deb ...
145s Unpacking python3-numpy (1:1.24.2-2) ...
145s Selecting previously unselected package python3-slow5.
145s Preparing to unpack .../11-python3-slow5_0.7.0+dfsg-2ubuntu4_arm64.deb ...
145s Unpacking python3-slow5 (0.7.0+dfsg-2ubuntu4) ...
145s Selecting previously unselected package python3-lib2to3.
145s Preparing to unpack .../12-python3-lib2to3_3.11.5-1_all.deb ...
145s Unpacking python3-lib2to3 (3.11.5-1) ...
145s Selecting previously unselected package python3-distutils.
145s Preparing to unpack .../13-python3-distutils_3.11.5-1_all.deb ...
145s Unpacking python3-distutils (3.11.5-1) ...
145s Selecting previously unselected package python3-all.
145s Preparing to unpack .../14-python3-all_3.12.1-0ubuntu2_arm64.deb ...
145s Unpacking python3-all (3.12.1-0ubuntu2) ...
145s Setting up libstreamvbyte0:arm64 (0.4.1-4ubuntu1) ...
145s Setting up libblas3:arm64 (3.12.0-3) ...
145s update-alternatives: using /usr/lib/aarch64-linux-gnu/blas/libblas.so.3 to provide /usr/lib/aarch64-linux-gnu/libblas.so.3 (libblas.so.3-aarch64-linux-gnu) in auto mode
145s Setting up libslow5-0:arm64 (0.7.0+dfsg-2ubuntu4) ...
145s Setting up libgfortran5:arm64 (14-20240221-2.1ubuntu1) ...
145s Setting up libpython3.11-minimal:arm64 (3.11.8-1) ...
145s Setting up python3-lib2to3 (3.11.5-1) ...
146s Setting up python3-distutils (3.11.5-1) ...
146s python3.12: can't get files for byte-compilation
146s Setting up python3.11-minimal (3.11.8-1) ...
147s Setting up liblapack3:arm64 (3.12.0-3) ...
147s update-alternatives: using /usr/lib/aarch64-linux-gnu/lapack/liblapack.so.3 to provide /usr/lib/aarch64-linux-gnu/liblapack.so.3 (liblapack.so.3-aarch64-linux-gnu) in auto mode
147s Setting up libpython3.11-stdlib:arm64 (3.11.8-1) ...
147s Setting up python3-all (3.12.1-0ubuntu2) ...
147s Setting up libslow5-dev:arm64 (0.7.0+dfsg-2ubuntu4) ...
147s Setting up python3.11 (3.11.8-1) ...
147s Setting up python3-numpy (1:1.24.2-2) ...
149s Setting up python3-slow5 (0.7.0+dfsg-2ubuntu4) ...
149s Setting up autopkgtest-satdep (0) ...
149s Processing triggers for systemd (255.2-3ubuntu2) ...
150s Processing triggers for man-db (2.12.0-3) ...
150s Processing triggers for libc-bin (2.39-0ubuntu2) ...
154s (Reading database ... 76186 files and directories currently installed.)
154s Removing autopkgtest-satdep (0) ...
156s autopkgtest [15:33:15]: test run-pybinding-test: [-----------------------
156s Testing with python3.12 in /tmp/autopkgtest.AqTPfb/autopkgtest_tmp:
156s 05-Mar-24 15:33:15 - [DEBUG]: FILE: examples/example.slow5, mode: r
156s 05-Mar-24 15:33:15 - [DEBUG]: FILE: b'examples/example.slow5', mode: b'r'
156s 05-Mar-24 15:33:15 - [DEBUG]: Number of read_groups: 1
156s 05-Mar-24 15:33:15 - [DEBUG]: FILE: examples/example.slow5, mode: r
156s 05-Mar-24 15:33:15 - [DEBUG]: Creating/loading index...
156s [slow5_idx_init::INFO] Index file not found. Creating an index at 'examples/example.slow5.idx'.
156s 05-Mar-24 15:33:15 - [DEBUG]: get_aux_names starting
156s 05-Mar-24 15:33:15 - [DEBUG]: get_aux_names aux_len: 0
156s 05-Mar-24 15:33:15 - [WARNING]: get_aux_names ret is NULL
156s 05-Mar-24 15:33:15 - [DEBUG]: get_aux_types starting
156s 05-Mar-24 15:33:15 - [DEBUG]: get_aux_types aux_len: 0
156s 05-Mar-24 15:33:15 - [WARNING]: get_aux_types self.s5_aux_type is NULL
156s 05-Mar-24 15:33:15 - [WARNING]: get_read unknown aux name: read_number
156s 05-Mar-24 15:33:15 - [WARNING]: get_read unknown aux name: blah
156s 05-Mar-24 15:33:15 - [WARNING]: get_read unknown aux name: start_mux
156s 05-Mar-24 15:33:15 - [DEBUG]: slow5_get_next return: 0
156s 05-Mar-24 15:33:15 - [DEBUG]: slow5_get_next return: 0
156s 05-Mar-24 15:33:15 - [DEBUG]: slow5_get_next return: 0
156s 05-Mar-24 15:33:15 - [DEBUG]: slow5_get_next return: 0
156s 05-Mar-24 15:33:15 - [DEBUG]: slow5_get_next return: 0
156s 05-Mar-24 15:33:15 - [DEBUG]: slow5_get_next return: -1
156s 05-Mar-24 15:33:15 - [DEBUG]: slow5_get_next reached end of file (EOF)(-1): -1: ['SLOW5_ERR_EOF', 'End Of File reached']
156s [slow5_idx_get::ERROR] Read ID 'null_read' was not found. At src/slow5_idx.c:441
156s 05-Mar-24 15:33:15 - [DEBUG]: get_read return not 0: -7
156s 05-Mar-24 15:33:15 - [DEBUG]: slow5_get_hdr_keys head_len: 32
156s 05-Mar-24 15:33:15 - [DEBUG]: slow5_get_hdr_keys head_len: 32
156s 05-Mar-24 15:33:15 - [DEBUG]: examples/example.slow5 closed
156s 05-Mar-24 15:33:15 - [DEBUG]: FILE: examples/example2.slow5, mode: r
156s 05-Mar-24 15:33:15 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r'
156s 05-Mar-24 15:33:15 - [DEBUG]: Number of read_groups: 4
156s 05-Mar-24 15:33:15 - [DEBUG]: FILE: examples/example2.slow5, mode: r
156s 05-Mar-24 15:33:15 - [DEBUG]: Creating/loading index...
156s [slow5_idx_init::INFO] Index file not found. Creating an index at 'examples/example2.slow5.idx'.
156s 05-Mar-24 15:33:15 - [DEBUG]: get_aux_names starting
156s 05-Mar-24 15:33:15 - [DEBUG]: get_aux_names aux_len: 5
156s 05-Mar-24 15:33:15 - [DEBUG]: get_aux_types starting
156s 05-Mar-24 15:33:15 - [DEBUG]: get_aux_types aux_len: 5
156s 05-Mar-24 15:33:15 - [WARNING]: get_read unknown aux name: blah
156s 05-Mar-24 15:33:15 - [WARNING]: get_read unknown aux name: blah
156s 05-Mar-24 15:33:15 - [DEBUG]: get_aux_names starting
156s 05-Mar-24 15:33:15 - [DEBUG]: get_aux_names aux_len: 5
156s 05-Mar-24 15:33:15 - [DEBUG]: get_aux_types starting
156s 05-Mar-24 15:33:15 - [DEBUG]: get_aux_types aux_len: 5
156s 05-Mar-24 15:33:15 - [DEBUG]: slow5_get_next return: 0
156s 05-Mar-24 15:33:15 - [DEBUG]: slow5_get_next return: 0
156s 05-Mar-24 15:33:15 - [DEBUG]: slow5_get_next return: 0
156s 05-Mar-24 15:33:15 - [DEBUG]: slow5_get_next return: 0
156s 05-Mar-24 15:33:15 - [DEBUG]: slow5_get_next return: 0
156s 05-Mar-24 15:33:15 - [DEBUG]: slow5_get_next return: 0
156s 05-Mar-24 15:33:15 - [DEBUG]: slow5_get_next return: 0
156s 05-Mar-24 15:33:15 - [DEBUG]: slow5_get_next return: 0
156s 05-Mar-24 15:33:15 - [DEBUG]: slow5_get_next return: -1
156s 05-Mar-24 15:33:15 - [DEBUG]: slow5_get_next reached end of file (EOF)(-1): -1: ['SLOW5_ERR_EOF', 'End Of File reached']
156s 05-Mar-24 15:33:15 - [DEBUG]: examples/example2.slow5 closed
156s 05-Mar-24 15:33:15 - [DEBUG]: FILE: examples/example_write.slow5, mode: w
156s 05-Mar-24 15:33:15 - [DEBUG]: FILE: b'examples/example_write.slow5', mode: b'w'
156s 05-Mar-24 15:33:15 - [DEBUG]: Not writing blow5, skipping compression steps
156s 05-Mar-24 15:33:15 - [DEBUG]: FILE: examples/example2.slow5, mode: r
156s 05-Mar-24 15:33:15 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r'
156s 05-Mar-24 15:33:15 - [DEBUG]: Number of read_groups: 4
156s 05-Mar-24 15:33:15 - [DEBUG]: slow5_get_next return: 0
156s 05-Mar-24 15:33:15 - [DEBUG]: write_record: _record_type_validation running
156s 05-Mar-24 15:33:15 - [DEBUG]: write_record: _record_type_validation done
156s 05-Mar-24 15:33:15 - [DEBUG]: write_record: checking header stuff...
156s 05-Mar-24 15:33:15 - [DEBUG]: write_record: writting header...
156s 05-Mar-24 15:33:15 - [DEBUG]: write_record: header written
156s 05-Mar-24 15:33:15 - [DEBUG]: write_record: slow5_rec_init()
156s 05-Mar-24 15:33:15 - [DEBUG]: write_record: self.write assignments...
156s 05-Mar-24 15:33:15 - [DEBUG]: write_record: self.write.raw_signal malloc...
156s 05-Mar-24 15:33:15 - [DEBUG]: write_record: self.write.raw_signal malloc done
156s 05-Mar-24 15:33:15 - [DEBUG]: write_record: self.write assignments done
156s 05-Mar-24 15:33:15 - [DEBUG]: write_record: self.write processing raw_signal
156s 05-Mar-24 15:33:15 - [DEBUG]: write_record: self.write raw_signal done
156s 05-Mar-24 15:33:15 - [DEBUG]: write_record: slow5_write()
156s 05-Mar-24 15:33:15 - [DEBUG]: write_record: slow5_write() ret: 305872
156s 05-Mar-24 15:33:15 - [DEBUG]: write_record: slow5_rec_free()
156s 05-Mar-24 15:33:15 - [DEBUG]: write_record: function complete, returning 0
156s 05-Mar-24 15:33:15 - [DEBUG]: slow5_get_next return: 0
156s 05-Mar-24 15:33:15 - [DEBUG]: write_record: _record_type_validation running
156s 05-Mar-24 15:33:15 - [DEBUG]: write_record: _record_type_validation done
156s 05-Mar-24 15:33:15 - [DEBUG]: write_record: slow5_rec_init()
156s 05-Mar-24 15:33:15 - [DEBUG]: write_record: self.write assignments...
156s 05-Mar-24 15:33:15 - [DEBUG]: write_record: self.write.raw_signal malloc...
156s 05-Mar-24 15:33:15 - [DEBUG]: write_record: self.write.raw_signal malloc done
156s 05-Mar-24 15:33:15 - [DEBUG]: write_record: self.write assignments done
156s 05-Mar-24 15:33:15 - [DEBUG]: write_record: self.write processing raw_signal
156s 05-Mar-24 15:33:15 - [DEBUG]: write_record: self.write raw_signal done
156s 05-Mar-24 15:33:15 - [DEBUG]: write_record: slow5_write()
156s 05-Mar-24 15:33:15 - [DEBUG]: write_record: slow5_write() ret: 152707
156s 05-Mar-24 15:33:15 - [DEBUG]: write_record: slow5_rec_free()
156s 05-Mar-24 15:33:15 - [DEBUG]: write_record: function complete, returning 0
156s 05-Mar-24 15:33:15 - [DEBUG]: slow5_get_next return: 0
156s 05-Mar-24 15:33:15 - [DEBUG]: write_record: _record_type_validation running
156s 05-Mar-24 15:33:15 - [DEBUG]: write_record: _record_type_validation done
156s 05-Mar-24 15:33:15 - [DEBUG]: write_record: slow5_rec_init()
156s 05-Mar-24 15:33:15 - [DEBUG]: write_record: self.write assignments...
157s 05-Mar-24 15:33:15 - [DEBUG]: write_record: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:15 - [DEBUG]: write_record: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:15 - [DEBUG]: write_record: self.write assignments done
157s 05-Mar-24 15:33:15 - [DEBUG]: write_record: self.write processing raw_signal
157s 05-Mar-24 15:33:15 - [DEBUG]: write_record: self.write raw_signal done
157s 05-Mar-24 15:33:15 - [DEBUG]: write_record: slow5_write()
157s 05-Mar-24 15:33:15 - [DEBUG]: write_record: slow5_write() ret: 305872
157s 05-Mar-24 15:33:15 - [DEBUG]: write_record: slow5_rec_free()
157s 05-Mar-24 15:33:15 - [DEBUG]: write_record: function complete, returning 0
157s 05-Mar-24 15:33:15 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:15 - [DEBUG]: write_record: _record_type_validation running
157s 05-Mar-24 15:33:15 - [DEBUG]: write_record: _record_type_validation done
157s 05-Mar-24 15:33:15 - [DEBUG]: write_record: slow5_rec_init()
157s 05-Mar-24 15:33:15 - [DEBUG]: write_record: self.write assignments...
157s 05-Mar-24 15:33:15 - [DEBUG]: write_record: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:15 - [DEBUG]: write_record: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:15 - [DEBUG]: write_record: self.write assignments done
157s 05-Mar-24 15:33:15 - [DEBUG]: write_record: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write() ret: 152707
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_free()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: function complete, returning 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation running
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write() ret: 305872
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_free()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: function complete, returning 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation running
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write() ret: 152707
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_free()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: function complete, returning 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation running
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write() ret: 305906
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_free()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: function complete, returning 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation running
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write() ret: 152741
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_free()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: function complete, returning 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: -1
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next reached end of file (EOF)(-1): -1: ['SLOW5_ERR_EOF', 'End Of File reached']
157s 05-Mar-24 15:33:16 - [DEBUG]: examples/example_write.slow5 closed
157s 05-Mar-24 15:33:16 - [DEBUG]: examples/example2.slow5 closed
157s 05-Mar-24 15:33:16 - [DEBUG]: FILE: examples/example_write_append.blow5, mode: w
157s 05-Mar-24 15:33:16 - [DEBUG]: FILE: b'examples/example_write_append.blow5', mode: b'w'
157s 05-Mar-24 15:33:16 - [DEBUG]: examples/example_write.slow5 already closed
157s 05-Mar-24 15:33:16 - [DEBUG]: pathname: examples/example_write.slow5
157s 05-Mar-24 15:33:16 - [DEBUG]: total_time_slow5_get_next: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_time_yield_reads: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_single_write_time: 0.025583982467651367 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_multi_write_time: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: FILE: examples/example2.slow5, mode: r
157s 05-Mar-24 15:33:16 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r'
157s 05-Mar-24 15:33:16 - [DEBUG]: Number of read_groups: 4
157s 05-Mar-24 15:33:16 - [DEBUG]: pathname: examples/example2.slow5
157s 05-Mar-24 15:33:16 - [DEBUG]: total_time_slow5_get_next: 0.01656961441040039 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_time_yield_reads: 0.017470359802246094 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_single_write_time: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_multi_write_time: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation running
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checking header stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: writting header...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: header written
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write() ret: 152976
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_free()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: function complete, returning 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation running
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write() ret: 76384
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_free()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: function complete, returning 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation running
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write() ret: 152976
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_free()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: function complete, returning 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation running
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write() ret: 76384
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_free()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: function complete, returning 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation running
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write() ret: 152976
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_free()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: function complete, returning 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation running
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write() ret: 76384
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_free()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: function complete, returning 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation running
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write() ret: 153010
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_free()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: function complete, returning 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation running
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write() ret: 76418
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_free()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: function complete, returning 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: -1
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next reached end of file (EOF)(-1): -1: ['SLOW5_ERR_EOF', 'End Of File reached']
157s 05-Mar-24 15:33:16 - [DEBUG]: examples/example2.slow5 closed
157s 05-Mar-24 15:33:16 - [DEBUG]: examples/example_write_append.blow5 closed
157s 05-Mar-24 15:33:16 - [DEBUG]: FILE: examples/example_write_append.blow5, mode: a
157s 05-Mar-24 15:33:16 - [DEBUG]: FILE: b'examples/example_write_append.blow5', mode: b'a'
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_hdr_keys head_len: 38
157s 05-Mar-24 15:33:16 - [DEBUG]: FILE: examples/example2.slow5, mode: r
157s 05-Mar-24 15:33:16 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r'
157s |==============================================|
157s |             pyslow5 test launch              |
157s |==============================================|
157s ['__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']
157s slow5 file opened and object created in: 0.001 seconds
157s ==============================================
157s get_read check, r1
157s get_read in: 0.0049 seconds
157s read_id: r1
157s read_group: 0
157s digitisation: 8192.0
157s offset: 23.0
157s range: 1467.61
157s sampling_rate: 4000.0
157s len_raw_signal: 59676
157s signal: [1039  588  588  593  586  574  570  585  588  586]
157s pylen of signal: 59676
157s AUX FIELDS:
157s read_number: None
157s start_mux: None
157s blah: None
157s ==============================================
157s get_read check, r4, converte to pA
157s get_read in: 0.006 seconds
157s read_id: r4
157s read_group: 0
157s digitisation: 8192.0
157s offset: 23.0
157s range: 1467.61
157s sampling_rate: 4000.0
157s len_raw_signal: 59670
157s signal: [190.25902  108.92418  109.46163  109.10333  107.67012  108.38673
157s  108.745026 109.10333  111.074    108.38673 ]
157s pylen of signal: 59670
157s signal value type: <class 'numpy.float32'>
157s ==============================================
157s seq_reads check, all reads
157s seq_reads readIDs:
157s type check reads: <class '_cython_3_0_5.generator'>
157s r1
157s r2
157s r3
157s r4
157s r5
157s seq_reads in: 0.012 seconds
157s ==============================================
157s Yield check, selected reads
157s get_read_list in: 0.0 seconds
157s yielded readIDs:
157s r1 r1
157s r3 r3
157s null_read read not found, None returned
157s r5 r5
157s r2 r2
157s r1 r1
157s ==============================================
157s Get headder names
157s header names:
157s ['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']
157s ==============================================
157s get_all_headers
157s {'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'}
157s ==============================================
157s Get headder attributes
157s flow_cell_id: FAB43577
157s exp_start_time: 1479433093
157s heatsink_temp: 33.9921875
157s asic_id: 3574887596
157s asic_id_eeprom: 0
157s asic_temp: 29.2145729
157s auto_update: 1
157s auto_update_source: https://mirror.oxfordnanoportal.com/software/MinKNOW/
157s bream_core_version: 1.1.20.1
157s bream_is_standard: 1
157s bream_map_version: 1.1.20.1
157s bream_ont_version: 1.1.20.1
157s bream_prod_version: 1.1.20.1
157s bream_rnd_version: 0.1.1
157s device_id: MN16450
157s exp_script_name: python/recipes/nc/NC_48Hr_Sequencing_Run_FLO-MIN106_SQK-LSK108.py
157s exp_script_purpose: sequencing_run
157s exp_start_time: 1479433093
157s experiment_kit: genomic_dna
157s experiment_type: customer_qc
157s file_version: 1
157s filename: deamernanopore_20161117_fnfab43577_mn16450_sequencing_run_ma_821_r9_4_na12878_11_17_16_88738
157s flow_cell_id: FAB43577
157s heatsink_temp: 33.9921875
157s hostname: DEAMERNANOPORE
157s installation_type: map
157s local_firmware_file: 0
157s operating_system: Windows 6.2
157s protocol_run_id: a4429838-103c-497f-a824-7dffa72cfd81
157s protocols_version: 1.1.20
157s run_id: d6e473a6d513ec6bfc150c60fd4556d72f0e6d18
157s sample_frequency: 4000
157s usb_config: 1.0.11_ONT#MinION_fpga_1.0.1#ctrl#Auto
157s user_filename_input: ma_821_r9.4_na12878_11_17_16
157s version: 1.1.20
157s ==============================================
157s get_read check, 0d624d4b-671f-40b8-9798-84f2ccc4d7fc
157s read_id: 0d624d4b-671f-40b8-9798-84f2ccc4d7fc
157s read_group: 3
157s digitisation: 8192.0
157s offset: 6.0
157s range: 1444.86
157s sampling_rate: 4000.0
157s len_raw_signal: 38164
157s signal: [1462 1075  795  801  797  788  817  791  801  802]
157s pylen of signal: 38164
157s AUX FIELDS:
157s read_number: 2287
157s start_mux: 2
157s blah: None
157s AUX FIELDS:
157s blah: None
157s AUX FIELDS:
157s read_number: 2287
157s ==============================================
157s Get aux names
157s aux names:
157s ['channel_number', 'median_before', 'read_number', 'start_mux', 'start_time']
157s ==============================================
157s Get aux types
157s aux types:
157s [22, 9, 2, 4, 7]
157s ==============================================
157s AUX FIELDS:
157s channel_number: 391
157s median_before: 260.557264
157s read_number: 2287
157s start_mux: 2
157s start_time: 36886851
157s ==============================================
157s seq_reads with aux:
157s type check reads: <class '_cython_3_0_5.generator'>
157s r0
157s read_number 4019
157s r1
157s read_number 2287
157s r2
157s read_number 4019
157s r3
157s read_number 2287
157s r4
157s read_number 4019
157s r5
157s read_number 2287
157s 0a238451-b9ed-446d-a152-badd074006c4
157s read_number 4019
157s 0d624d4b-671f-40b8-9798-84f2ccc4d7fc
157s read_number 2287
157s ==============================================
157s write reads no aux
157s ret: write_header(): 0
157s ret: write_record(): 0
157s ret: write_record(): 0
157s ret: write_record(): 0
157s ret: write_record(): 0
157s ret: write_record(): 0
157s ret: write_record(): 0
157s ret: write_record(): 0
157s ret: write_record(): 0
157s ==============================================
157s append reads no aux
157s ret: write_header(): 0
157s ret: write_record(): 0
157s ret: write_record(): 0
157s ret: write_record(): 0
157s ret: write_record(): 0
157s ret: write_record(): 0
157s ret: write_record(): 0
157s ret: write_record(): 0
157s ret: write_record(): 0
157s get_all_headers
157s 05-Mar-24 15:33:16 - [DEBUG]: Number of read_groups: 4
157s 05-Mar-24 15:33:16 - [DEBUG]: pathname: examples/example2.slow5
157s 05-Mar-24 15:33:16 - [DEBUG]: total_time_slow5_get_next: 0.017911195755004883 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_time_yield_reads: 0.01872110366821289 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_single_write_time: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_multi_write_time: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation running
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write() ret: 152983
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_free()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: function complete, returning 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation running
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write() ret: 76391
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_free()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: function complete, returning 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation running
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write() ret: 152983
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_free()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: function complete, returning 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation running
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write() ret: 76391
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_free()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: function complete, returning 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation running
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write() ret: 152983
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_free()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: function complete, returning 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation running
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write() ret: 76391
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_free()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: function complete, returning 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation running
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write() ret: 153017
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_free()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: function complete, returning 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation running
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write() ret: 76425
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_free()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: function complete, returning 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: -1
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next reached end of file (EOF)(-1): -1: ['SLOW5_ERR_EOF', 'End Of File reached']
157s 05-Mar-24 15:33:16 - [DEBUG]: examples/example2.slow5 closed
157s 05-Mar-24 15:33:16 - [DEBUG]: examples/example_write_append.blow5 closed
157s 05-Mar-24 15:33:16 - [DEBUG]: FILE: examples/example_write_aux.blow5, mode: w
157s 05-Mar-24 15:33:16 - [DEBUG]: FILE: b'examples/example_write_aux.blow5', mode: b'w'
157s 05-Mar-24 15:33:16 - [DEBUG]: examples/example_write_append.blow5 already closed
157s 05-Mar-24 15:33:16 - [DEBUG]: pathname: examples/example_write_append.blow5
157s 05-Mar-24 15:33:16 - [DEBUG]: total_time_slow5_get_next: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_time_yield_reads: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_single_write_time: 0.02467489242553711 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_multi_write_time: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: FILE: examples/example2.slow5, mode: r
157s 05-Mar-24 15:33:16 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r'
157s 05-Mar-24 15:33:16 - [DEBUG]: Number of read_groups: 4
157s 05-Mar-24 15:33:16 - [DEBUG]: pathname: examples/example2.slow5
157s 05-Mar-24 15:33:16 - [DEBUG]: total_time_slow5_get_next: 0.017803430557250977 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_time_yield_reads: 0.019104719161987305 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_single_write_time: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_multi_write_time: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: get_aux_names starting
157s 05-Mar-24 15:33:16 - [DEBUG]: get_aux_names aux_len: 5
157s 05-Mar-24 15:33:16 - [DEBUG]: get_aux_types starting
157s 05-Mar-24 15:33:16 - [DEBUG]: get_aux_types aux_len: 5
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation running
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checking header stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: writting header...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: header written
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: channel_number: 281
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string running...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string type: <class 'str'>
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: median_before: 231.363533
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: read_number: 4019
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: start_mux: 1
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: start_time: 78470500
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: aux stuff done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write() ret: 67258
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_free()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: function complete, returning 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation running
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: channel_number: 391
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string running...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string type: <class 'str'>
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: median_before: 260.557264
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: read_number: 2287
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: start_mux: 2
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: start_time: 36886851
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: aux stuff done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write() ret: 32408
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_free()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: function complete, returning 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation running
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: channel_number: 281
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string running...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string type: <class 'str'>
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: median_before: 231.363533
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: read_number: 4019
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: start_mux: 1
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: start_time: 78470500
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: aux stuff done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write() ret: 67258
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_free()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: function complete, returning 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation running
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: channel_number: 391
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string running...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string type: <class 'str'>
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: median_before: 260.557264
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: read_number: 2287
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: start_mux: 2
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: start_time: 36886851
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: aux stuff done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write() ret: 32408
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_free()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: function complete, returning 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation running
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: channel_number: 281
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string running...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string type: <class 'str'>
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: median_before: 231.363533
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: read_number: 4019
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: start_mux: 1
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: start_time: 78470500
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: aux stuff done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write() ret: 67260
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_free()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: function complete, returning 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation running
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: channel_number: 391
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string running...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string type: <class 'str'>
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: median_before: 260.557264
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: read_number: 2287
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: start_mux: 2
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: start_time: 36886851
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: aux stuff done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write() ret: 32408
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_free()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: function complete, returning 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation running
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: channel_number: 281
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string running...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string type: <class 'str'>
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: median_before: 231.363533
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: read_number: 4019
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: start_mux: 1
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: start_time: 78470500
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: aux stuff done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write() ret: 67298
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_free()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: function complete, returning 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation running
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: channel_number: 391
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string running...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string type: <class 'str'>
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: median_before: 260.557264
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: read_number: 2287
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: start_mux: 2
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: start_time: 36886851
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: aux stuff done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write() ret: 32446
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_free()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: function complete, returning 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: -1
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next reached end of file (EOF)(-1): -1: ['SLOW5_ERR_EOF', 'End Of File reached']
157s 05-Mar-24 15:33:16 - [DEBUG]: examples/example2.slow5 closed
157s 05-Mar-24 15:33:16 - [DEBUG]: examples/example_write_aux.blow5 closed
157s 05-Mar-24 15:33:16 - [DEBUG]: FILE: examples/example_write_append_aux.blow5, mode: w
157s 05-Mar-24 15:33:16 - [DEBUG]: FILE: b'examples/example_write_append_aux.blow5', mode: b'w'
157s 05-Mar-24 15:33:16 - [DEBUG]: examples/example_write_aux.blow5 already closed
157s 05-Mar-24 15:33:16 - [DEBUG]: pathname: examples/example_write_aux.blow5
157s 05-Mar-24 15:33:16 - [DEBUG]: total_time_slow5_get_next: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_time_yield_reads: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_single_write_time: 0.02609395980834961 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_multi_write_time: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: FILE: examples/example2.slow5, mode: r
157s 05-Mar-24 15:33:16 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r'
157s 05-Mar-24 15:33:16 - [DEBUG]: Number of read_groups: 4
157s 05-Mar-24 15:33:16 - [DEBUG]: pathname: examples/example2.slow5
157s 05-Mar-24 15:33:16 - [DEBUG]: total_time_slow5_get_next: 0.017720699310302734 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_time_yield_reads: 0.018778085708618164 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_single_write_time: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_multi_write_time: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: get_aux_names starting
157s 05-Mar-24 15:33:16 - [DEBUG]: get_aux_names aux_len: 5
157s 05-Mar-24 15:33:16 - [DEBUG]: get_aux_types starting
157s 05-Mar-24 15:33:16 - [DEBUG]: get_aux_types aux_len: 5
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation running
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checking header stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: writting header...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: header written
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: channel_number: 281
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string running...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string type: <class 'str'>
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: median_before: 231.363533
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: read_number: 4019
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: start_mux: 1
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: start_time: 78470500
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: aux stuff done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write() ret: 153008
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_free()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: function complete, returning 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation running
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: channel_number: 391
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string running...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string type: <class 'str'>
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: median_before: 260.557264
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: read_number: 2287
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: start_mux: 2
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: start_time: 36886851
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: aux stuff done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write() ret: 76416
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_free()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: function complete, returning 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation running
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: channel_number: 281
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string running...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string type: <class 'str'>
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: median_before: 231.363533
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: read_number: 4019
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: start_mux: 1
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: start_time: 78470500
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: aux stuff done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write() ret: 153008
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_free()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: function complete, returning 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation running
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: channel_number: 391
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string running...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string type: <class 'str'>
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: median_before: 260.557264
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: read_number: 2287
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: start_mux: 2
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: start_time: 36886851
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: aux stuff done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write() ret: 76416
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_free()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: function complete, returning 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation running
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: channel_number: 281
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string running...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string type: <class 'str'>
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: median_before: 231.363533
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: read_number: 4019
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: start_mux: 1
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: start_time: 78470500
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: aux stuff done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write() ret: 153008
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_free()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: function complete, returning 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation running
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: channel_number: 391
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string running...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string type: <class 'str'>
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: median_before: 260.557264
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: read_number: 2287
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: start_mux: 2
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: start_time: 36886851
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: aux stuff done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write() ret: 76416
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_free()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: function complete, returning 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation running
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: channel_number: 281
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string running...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string type: <class 'str'>
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: median_before: 231.363533
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: read_number: 4019
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: start_mux: 1
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: start_time: 78470500
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: aux stuff done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write() ret: 153042
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_free()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: function complete, returning 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation running
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: channel_number: 391
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string running...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string type: <class 'str'>
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: median_before: 260.557264
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: read_number: 2287
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: start_mux: 2
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: start_time: 36886851
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: aux stuff done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write() ret: 76450
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_free()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: function complete, returning 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: -1
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next reached end of file (EOF)(-1): -1: ['SLOW5_ERR_EOF', 'End Of File reached']
157s 05-Mar-24 15:33:16 - [DEBUG]: examples/example2.slow5 closed
157s 05-Mar-24 15:33:16 - [DEBUG]: examples/example_write_append_aux.blow5 closed
157s 05-Mar-24 15:33:16 - [DEBUG]: FILE: examples/example_write_append_aux.blow5, mode: a
157s 05-Mar-24 15:33:16 - [DEBUG]: FILE: b'examples/example_write_append_aux.blow5', mode: b'a'
157s 05-Mar-24 15:33:16 - [DEBUG]: examples/example_write_append.blow5 already closed
157s 05-Mar-24 15:33:16 - [DEBUG]: pathname: examples/example_write_append.blow5
157s 05-Mar-24 15:33:16 - [DEBUG]: total_time_slow5_get_next: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_time_yield_reads: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_single_write_time: 0.025189638137817383 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_multi_write_time: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: FILE: examples/example2.slow5, mode: r
157s 05-Mar-24 15:33:16 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r'
157s 05-Mar-24 15:33:16 - [DEBUG]: Number of read_groups: 4
157s 05-Mar-24 15:33:16 - [DEBUG]: pathname: examples/example2.slow5
157s 05-Mar-24 15:33:16 - [DEBUG]: total_time_slow5_get_next: 0.018293142318725586 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_time_yield_reads: 0.019417762756347656 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_single_write_time: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_multi_write_time: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: get_aux_names starting
157s 05-Mar-24 15:33:16 - [DEBUG]: get_aux_names aux_len: 5
157s 05-Mar-24 15:33:16 - [DEBUG]: get_aux_types starting
157s 05-Mar-24 15:33:16 - [DEBUG]: get_aux_types aux_len: 5
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation running
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: channel_number: 281
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string running...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string type: <class 'str'>
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: median_before: 231.363533
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: read_number: 4019
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: start_mux: 1
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: start_time: 78470500
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: aux stuff done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write() ret: 153015
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_free()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: function complete, returning 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation running
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: channel_number: 391
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string running...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string type: <class 'str'>
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: median_before: 260.557264
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: read_number: 2287
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: start_mux: 2
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: start_time: 36886851
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: aux stuff done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write() ret: 76423
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_free()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: function complete, returning 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation running
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: channel_number: 281
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string running...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string type: <class 'str'>
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: median_before: 231.363533
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: read_number: 4019
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: start_mux: 1
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: start_time: 78470500
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: aux stuff done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write() ret: 153015
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_free()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: function complete, returning 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation running
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: channel_number: 391
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string running...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string type: <class 'str'>
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: median_before: 260.557264
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: read_number: 2287
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: start_mux: 2
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: start_time: 36886851
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: aux stuff done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write() ret: 76423
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_free()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: function complete, returning 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation running
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: channel_number: 281
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string running...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string type: <class 'str'>
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: median_before: 231.363533
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: read_number: 4019
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: start_mux: 1
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: start_time: 78470500
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: aux stuff done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write() ret: 153015
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_free()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: function complete, returning 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation running
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: channel_number: 391
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string running...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string type: <class 'str'>
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: median_before: 260.557264
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: read_number: 2287
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: start_mux: 2
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: start_time: 36886851
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: aux stuff done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write() ret: 76423
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_free()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: function complete, returning 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation running
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: channel_number: 281
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string running...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string type: <class 'str'>
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: median_before: 231.363533
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: read_number: 4019
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: start_mux: 1
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: start_time: 78470500
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: aux stuff done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write() ret: 153049
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_free()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: function complete, returning 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation running
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: _record_type_validation done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: channel_number: 391
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string running...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string type: <class 'str'>
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: median_before: 260.557264
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: read_number: 2287
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: start_mux: 2
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: checked_aux: start_time: 36886851
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: aux stuff done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_write() ret: 76457
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: slow5_rec_free()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record: function complete, returning 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: -1
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next reached end of file (EOF)(-1): -1: ['SLOW5_ERR_EOF', 'End Of File reached']
157s 05-Mar-24 15:33:16 - [DEBUG]: examples/example2.slow5 closed
157s 05-Mar-24 15:33:16 - [DEBUG]: examples/example_write_append_aux.blow5 closed
157s 05-Mar-24 15:33:16 - [DEBUG]: FILE: examples/example2.slow5, mode: r
157s 05-Mar-24 15:33:16 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r'
157s 05-Mar-24 15:33:16 - [DEBUG]: Number of read_groups: 4
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next_multi return: 3
157s 05-Mar-24 15:33:16 - [DEBUG]: get_aux_names starting
157s 05-Mar-24 15:33:16 - [DEBUG]: get_aux_names aux_len: 5
157s 05-Mar-24 15:33:16 - [DEBUG]: get_aux_types starting
157s 05-Mar-24 15:33:16 - [DEBUG]: get_aux_types aux_len: 5
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next_multi return: 3
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next_multi return: 2
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next_multi has no more batches - batchsize:3 ret:2
157s 05-Mar-24 15:33:16 - [DEBUG]: seq_reads_multi timings:
157s 05-Mar-24 15:33:16 - [DEBUG]: aux_total_time: 0.00023603439331054688
157s 05-Mar-24 15:33:16 - [DEBUG]: primary_total_time: 0.00021338462829589844
157s 05-Mar-24 15:33:16 - [DEBUG]: pA_total_time: 0.0014913082122802734
157s 05-Mar-24 15:33:16 - [DEBUG]: signal_total_time: 0.00019669532775878906
157s 05-Mar-24 15:33:16 - [DEBUG]: examples/example2.slow5 closed
157s 05-Mar-24 15:33:16 - [DEBUG]: FILE: examples/example2.slow5, mode: r
157s 05-Mar-24 15:33:16 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r'
157s 05-Mar-24 15:33:16 - [DEBUG]: Number of read_groups: 4
157s 05-Mar-24 15:33:16 - [DEBUG]: pathname: examples/example2.slow5
157s 05-Mar-24 15:33:16 - [DEBUG]: total_time_slow5_get_next: 0.012405872344970703 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_time_yield_reads: 0.0019676685333251953 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_single_write_time: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_multi_write_time: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: FILE: examples/example2.slow5, mode: r
157s 05-Mar-24 15:33:16 - [DEBUG]: Creating/loading index...
157s 05-Mar-24 15:33:16 - [DEBUG]: Setting up batching...
157s 05-Mar-24 15:33:16 - [DEBUG]: read_list: ['r0', 'r1', 'r2', 'r3', 'r4', 'r5', '0a238451-b9ed-446d-a152-badd074006c4', '0d624d4b-671f-40b8-9798-84f2ccc4d7fc']
157s 05-Mar-24 15:33:16 - [DEBUG]: batch for loop start
157s 05-Mar-24 15:33:16 - [DEBUG]: Batch: r0,r1,r2
157s 05-Mar-24 15:33:16 - [DEBUG]: Starting rid assignment
157s 05-Mar-24 15:33:16 - [DEBUG]: readID: r0, bin: b'r0'
157s 05-Mar-24 15:33:16 - [DEBUG]: readID: r1, bin: b'r1'
157s 05-Mar-24 15:33:16 - [DEBUG]: readID: r2, bin: b'r2'
157s 05-Mar-24 15:33:16 - [DEBUG]: rid assignment complete
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_batch: num_reads: 3
157s 05-Mar-24 15:33:16 - [DEBUG]: get_read_multi slow5_get_batch ret: 3
157s 05-Mar-24 15:33:16 - [DEBUG]: get_aux_names starting
157s 05-Mar-24 15:33:16 - [DEBUG]: get_aux_names aux_len: 5
157s 05-Mar-24 15:33:16 - [DEBUG]: get_aux_types starting
157s 05-Mar-24 15:33:16 - [DEBUG]: get_aux_types aux_len: 5
157s 05-Mar-24 15:33:16 - [DEBUG]: Batch: r3,r4,r5
157s 05-Mar-24 15:33:16 - [DEBUG]: Starting rid assignment
157s 05-Mar-24 15:33:16 - [DEBUG]: readID: r3, bin: b'r3'
157s 05-Mar-24 15:33:16 - [DEBUG]: readID: r4, bin: b'r4'
157s 05-Mar-24 15:33:16 - [DEBUG]: readID: r5, bin: b'r5'
157s 05-Mar-24 15:33:16 - [DEBUG]: rid assignment complete
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_batch: num_reads: 3
157s 05-Mar-24 15:33:16 - [DEBUG]: get_read_multi slow5_get_batch ret: 3
157s 05-Mar-24 15:33:16 - [DEBUG]: Batch: 0a238451-b9ed-446d-a152-badd074006c4,0d624d4b-671f-40b8-9798-84f2ccc4d7fc
157s 05-Mar-24 15:33:16 - [DEBUG]: Starting rid assignment
157s 05-Mar-24 15:33:16 - [DEBUG]: readID: 0a238451-b9ed-446d-a152-badd074006c4, bin: b'0a238451-b9ed-446d-a152-badd074006c4'
157s 05-Mar-24 15:33:16 - [DEBUG]: readID: 0d624d4b-671f-40b8-9798-84f2ccc4d7fc, bin: b'0d624d4b-671f-40b8-9798-84f2ccc4d7fc'
157s 05-Mar-24 15:33:16 - [DEBUG]: rid assignment complete
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_batch: num_reads: 2
157s 05-Mar-24 15:33:16 - [DEBUG]: get_read_multi slow5_get_batch ret: 2
157s 05-Mar-24 15:33:16 - [DEBUG]: seq_reads_multi timings:
157s 05-Mar-24 15:33:16 - [DEBUG]: examples/example2.slow5 closed
157s 05-Mar-24 15:33:16 - [DEBUG]: FILE: examples/example_write_aux_multi.slow5, mode: w
157s 05-Mar-24 15:33:16 - [DEBUG]: FILE: b'examples/example_write_aux_multi.slow5', mode: b'w'
157s 05-Mar-24 15:33:16 - [DEBUG]: Not writing blow5, skipping compression steps
157s 05-Mar-24 15:33:16 - [DEBUG]: examples/example_write_append_aux.blow5 already closed
157s 05-Mar-24 15:33:16 - [DEBUG]: pathname: examples/example_write_append_aux.blow5
157s 05-Mar-24 15:33:16 - [DEBUG]: total_time_slow5_get_next: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_time_yield_reads: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_single_write_time: 0.025362730026245117 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_multi_write_time: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: FILE: examples/example2.slow5, mode: r
157s 05-Mar-24 15:33:16 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r'
157s 05-Mar-24 15:33:16 - [DEBUG]: Number of read_groups: 4
157s 05-Mar-24 15:33:16 - [DEBUG]: pathname: examples/example2.slow5
157s 05-Mar-24 15:33:16 - [DEBUG]: total_time_slow5_get_next: 0.018629074096679688 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_time_yield_reads: 0.020068883895874023 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_single_write_time: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_multi_write_time: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: get_aux_names starting
157s 05-Mar-24 15:33:16 - [DEBUG]: get_aux_names aux_len: 5
157s 05-Mar-24 15:33:16 - [DEBUG]: get_aux_types starting
157s 05-Mar-24 15:33:16 - [DEBUG]: get_aux_types aux_len: 5
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: 0
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next return: -1
157s 05-Mar-24 15:33:16 - [DEBUG]: slow5_get_next reached end of file (EOF)(-1): -1: ['SLOW5_ERR_EOF', 'End Of File reached']
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: Setting up batching...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: batch for loop start
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: _record_type_validation running
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux stuff done
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux stuff done
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux stuff done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: _record_type_validation done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: checking header stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: writting header...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: header written
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: checked_aux: channel_number: 281
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: slow5_aux_set_string running...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: slow5_aux_set_string type: <class 'str'>
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: slow5_aux_set_string running done: ret = 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: checked_aux: median_before: 231.363533
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: checked_aux: read_number: 4019
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: checked_aux: start_mux: 1
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: checked_aux: start_time: 78470500
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: aux stuff done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: checked_aux: channel_number: 391
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: slow5_aux_set_string running...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: slow5_aux_set_string type: <class 'str'>
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: slow5_aux_set_string running done: ret = 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: checked_aux: median_before: 260.557264
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: checked_aux: read_number: 2287
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: checked_aux: start_mux: 2
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: checked_aux: start_time: 36886851
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: aux stuff done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: checked_aux: channel_number: 281
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: slow5_aux_set_string running...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: slow5_aux_set_string type: <class 'str'>
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: slow5_aux_set_string running done: ret = 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: checked_aux: median_before: 231.363533
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: checked_aux: read_number: 4019
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: checked_aux: start_mux: 1
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: checked_aux: start_time: 78470500
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: aux stuff done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: slow5_write_batch()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: free()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: free() aux
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: _record_type_validation running
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux stuff done
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux stuff done
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux stuff done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: _record_type_validation done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: checked_aux: channel_number: 391
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: slow5_aux_set_string running...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: slow5_aux_set_string type: <class 'str'>
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: slow5_aux_set_string running done: ret = 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: checked_aux: median_before: 260.557264
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: checked_aux: read_number: 2287
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: checked_aux: start_mux: 2
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: checked_aux: start_time: 36886851
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: aux stuff done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: checked_aux: channel_number: 281
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: slow5_aux_set_string running...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: slow5_aux_set_string type: <class 'str'>
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: slow5_aux_set_string running done: ret = 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: checked_aux: median_before: 231.363533
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: checked_aux: read_number: 4019
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: checked_aux: start_mux: 1
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: checked_aux: start_time: 78470500
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: aux stuff done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: checked_aux: channel_number: 391
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: slow5_aux_set_string running...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: slow5_aux_set_string type: <class 'str'>
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: slow5_aux_set_string running done: ret = 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: checked_aux: median_before: 260.557264
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: checked_aux: read_number: 2287
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: checked_aux: start_mux: 2
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: checked_aux: start_time: 36886851
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: aux stuff done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: slow5_write_batch()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: free()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: free() aux
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: _record_type_validation running
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux stuff done
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: doing aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux passed tests...
157s 05-Mar-24 15:33:16 - [DEBUG]: _record_type_validation: aux stuff done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: _record_type_validation done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: checked_aux: channel_number: 281
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: slow5_aux_set_string running...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: slow5_aux_set_string type: <class 'str'>
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: slow5_aux_set_string running done: ret = 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: checked_aux: median_before: 231.363533
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: checked_aux: read_number: 4019
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: checked_aux: start_mux: 1
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: checked_aux: start_time: 78470500
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: aux stuff done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: slow5_rec_init()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: self.write assignments...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: self.write.raw_signal malloc...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: self.write.raw_signal malloc done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: self.write assignments done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: self.write processing raw_signal
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: self.write raw_signal done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: aux stuff...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: checked_aux: channel_number: 391
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: slow5_aux_set_string running...
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: slow5_aux_set_string type: <class 'str'>
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: slow5_aux_set_string running done: ret = 0
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: checked_aux: median_before: 260.557264
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: checked_aux: read_number: 2287
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: checked_aux: start_mux: 2
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: checked_aux: start_time: 36886851
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: aux stuff done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: slow5_write_batch()
157s {'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'}
157s ret: write_record(): 0
157s ret: write_record(): 0
157s ret: write_record(): 0
157s ret: write_record(): 0
157s ret: write_record(): 0
157s ret: write_record(): 0
157s ret: write_record(): 0
157s ret: write_record(): 0
157s ==============================================
157s write reads with aux
157s ret: write_header(): 0
157s ret: write_header(): 0
157s ret: write_record(): 0
157s ret: write_record(): 0
157s ret: write_record(): 0
157s ret: write_record(): 0
157s ret: write_record(): 0
157s ret: write_record(): 0
157s ret: write_record(): 0
157s ret: write_record(): 0
157s ==============================================
157s append reads with aux
157s ret: write_header(): 0
157s ret: write_header(): 0
157s ret: write_record(): 0
157s ret: write_record(): 0
157s ret: write_record(): 0
157s ret: write_record(): 0
157s ret: write_record(): 0
157s ret: write_record(): 0
157s ret: write_record(): 0
157s ret: write_record(): 0
157s ret: write_record(): 0
157s ret: write_record(): 0
157s ret: write_record(): 0
157s ret: write_record(): 0
157s ret: write_record(): 0
157s ret: write_record(): 0
157s ret: write_record(): 0
157s ret: write_record(): 0
157s ==============================================
157s seq_reads_multi with aux:
157s type check reads: <class '_cython_3_0_5.generator'>
157s r0
157s read_number 4019
157s r1
157s read_number 2287
157s r2
157s read_number 4019
157s r3
157s read_number 2287
157s r4
157s read_number 4019
157s r5
157s read_number 2287
157s 0a238451-b9ed-446d-a152-badd074006c4
157s read_number 4019
157s 0d624d4b-671f-40b8-9798-84f2ccc4d7fc
157s read_number 2287
157s ==============================================
157s get_reads_multi with aux:
157s type check reads: <class '_cython_3_0_5.generator'>
157s r0
157s read_number 4019
157s r1
157s read_number 2287
157s r2
157s read_number 4019
157s r3
157s read_number 2287
157s r4
157s read_number 4019
157s r5
157s read_number 2287
157s 0a238451-b9ed-446d-a152-badd074006c4
157s read_number 4019
157s 0d624d4b-671f-40b8-9798-84f2ccc4d7fc
157s read_number 2287
157s ==============================================
157s write reads with aux multi
157s ret: write_header(): 0
157s ret: write_header(): 0
157s {'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)}}
157s {'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}}
157s ret: write_record(): 0
157s ==============================================
157s get all readIDs from index
157s ['r0', 'r1', 'r2', 'r3', 'r4', 'r5', '0a238451-b9ed-446d-a152-badd074006c4', '0d624d4b-671f-40b8-9798-84f2ccc4d7fc']
157s number of reads: 8
157s ==============================================
157s done
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: free()
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: free() aux
157s 05-Mar-24 15:33:16 - [DEBUG]: write_record_batch: function complete, returning 0
157s 05-Mar-24 15:33:16 - [DEBUG]: examples/example2.slow5 closed
157s 05-Mar-24 15:33:16 - [DEBUG]: examples/example_write_aux_multi.slow5 closed
157s 05-Mar-24 15:33:16 - [DEBUG]: FILE: examples/example2.slow5, mode: r
157s 05-Mar-24 15:33:16 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r'
157s 05-Mar-24 15:33:16 - [DEBUG]: Number of read_groups: 4
157s 05-Mar-24 15:33:16 - [DEBUG]: pathname: examples/example2.slow5
157s 05-Mar-24 15:33:16 - [DEBUG]: total_time_slow5_get_next: 0.016780376434326172 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_time_yield_reads: 0.01781320571899414 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_single_write_time: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_multi_write_time: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: FILE: examples/example2.slow5, mode: r
157s 05-Mar-24 15:33:16 - [DEBUG]: Creating/loading index...
157s 05-Mar-24 15:33:16 - [DEBUG]: examples/example2.slow5 closed
157s 05-Mar-24 15:33:16 - [DEBUG]: pathname: examples/example.slow5
157s 05-Mar-24 15:33:16 - [DEBUG]: total_time_slow5_get_next: 0.011320114135742188 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_time_yield_reads: 0.011881351470947266 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_single_write_time: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_multi_write_time: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: pathname: examples/example2.slow5
157s 05-Mar-24 15:33:16 - [DEBUG]: total_time_slow5_get_next: 0.018259763717651367 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_time_yield_reads: 0.020984649658203125 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_single_write_time: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_multi_write_time: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: examples/example_write_aux_multi.slow5 already closed
157s 05-Mar-24 15:33:16 - [DEBUG]: pathname: examples/example_write_aux_multi.slow5
157s 05-Mar-24 15:33:16 - [DEBUG]: total_time_slow5_get_next: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_time_yield_reads: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_single_write_time: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_multi_write_signal_time: 0.025811195373535156 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_multi_write_time: 0.05239462852478027 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: pathname: examples/example2.slow5
157s 05-Mar-24 15:33:16 - [DEBUG]: total_time_slow5_get_next: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_time_yield_reads: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_single_write_time: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_multi_write_time: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: examples/example_write_append_aux.blow5 already closed
157s 05-Mar-24 15:33:16 - [DEBUG]: pathname: examples/example_write_append_aux.blow5
157s 05-Mar-24 15:33:16 - [DEBUG]: total_time_slow5_get_next: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_time_yield_reads: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_single_write_time: 0.026948213577270508 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_multi_write_time: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: pathname: examples/example2.slow5
157s 05-Mar-24 15:33:16 - [DEBUG]: total_time_slow5_get_next: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_time_yield_reads: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_single_write_time: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds
157s 05-Mar-24 15:33:16 - [DEBUG]: total_multi_write_time: 0.0 seconds
157s autopkgtest [15:33:16]: test run-pybinding-test: -----------------------]
158s autopkgtest [15:33:17]: test run-pybinding-test:  - - - - - - - - - - results - - - - - - - - - -
158s run-pybinding-test   PASS
158s autopkgtest [15:33:17]: test run-pkg-test: preparing testbed
259s autopkgtest [15:34:58]: @@@@@@@@@@@@@@@@@@@@ test bed setup
259s Get:1 http://ftpmaster.internal/ubuntu noble-proposed InRelease [117 kB]
260s Get:2 http://ftpmaster.internal/ubuntu noble-proposed/multiverse Sources [24.5 kB]
260s Get:3 http://ftpmaster.internal/ubuntu noble-proposed/universe Sources [1807 kB]
260s Get:4 http://ftpmaster.internal/ubuntu noble-proposed/restricted Sources [3976 B]
260s Get:5 http://ftpmaster.internal/ubuntu noble-proposed/main Sources [322 kB]
260s Get:6 http://ftpmaster.internal/ubuntu noble-proposed/main arm64 Packages [427 kB]
260s Get:7 http://ftpmaster.internal/ubuntu noble-proposed/main arm64 c-n-f Metadata [3144 B]
260s Get:8 http://ftpmaster.internal/ubuntu noble-proposed/restricted arm64 Packages [20.3 kB]
260s Get:9 http://ftpmaster.internal/ubuntu noble-proposed/restricted arm64 c-n-f Metadata [116 B]
260s Get:10 http://ftpmaster.internal/ubuntu noble-proposed/universe arm64 Packages [2077 kB]
261s Get:11 http://ftpmaster.internal/ubuntu noble-proposed/universe arm64 c-n-f Metadata [8528 B]
261s Get:12 http://ftpmaster.internal/ubuntu noble-proposed/multiverse arm64 Packages [14.3 kB]
261s Get:13 http://ftpmaster.internal/ubuntu noble-proposed/multiverse arm64 c-n-f Metadata [116 B]
262s Fetched 4824 kB in 2s (2818 kB/s)
262s Reading package lists...
265s Reading package lists...
265s Building dependency tree...
265s Reading state information...
266s Calculating upgrade...
267s The following packages will be upgraded:
267s   zlib1g
267s 1 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.
267s Need to get 61.7 kB of archives.
267s After this operation, 0 B of additional disk space will be used.
267s Get:1 http://ftpmaster.internal/ubuntu noble-proposed/main arm64 zlib1g arm64 1:1.3.dfsg-3.1ubuntu1 [61.7 kB]
268s Fetched 61.7 kB in 0s (182 kB/s)
269s (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 ... 74660 files and directories currently installed.)
269s Preparing to unpack .../zlib1g_1%3a1.3.dfsg-3.1ubuntu1_arm64.deb ...
269s Unpacking zlib1g:arm64 (1:1.3.dfsg-3.1ubuntu1) over (1:1.3.dfsg-3ubuntu1) ...
269s Setting up zlib1g:arm64 (1:1.3.dfsg-3.1ubuntu1) ...
269s Processing triggers for libc-bin (2.39-0ubuntu2) ...
269s Reading package lists...
270s Building dependency tree...
270s Reading state information...
270s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.
272s sh: Attempting to set up Debian/Ubuntu apt sources automatically
272s sh: Distribution appears to be Ubuntu
274s Reading package lists...
274s Building dependency tree...
274s Reading state information...
276s eatmydata is already the newest version (131-1).
276s dbus is already the newest version (1.14.10-4ubuntu1).
276s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.
276s Reading package lists...
277s Building dependency tree...
277s Reading state information...
278s rng-tools-debian is already the newest version (2.4).
278s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.
279s Reading package lists...
279s Building dependency tree...
279s Reading state information...
281s haveged is already the newest version (1.9.14-1ubuntu1).
281s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.
281s Reading package lists...
281s Building dependency tree...
281s Reading state information...
282s The following packages will be REMOVED:
282s   cloud-init* python3-configobj* python3-debconf*
283s 0 upgraded, 0 newly installed, 3 to remove and 0 not upgraded.
283s After this operation, 3248 kB disk space will be freed.
283s (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 ... 74660 files and directories currently installed.)
283s Removing cloud-init (24.1-0ubuntu1) ...
284s Removing python3-configobj (5.0.8-3) ...
284s Removing python3-debconf (1.5.86) ...
284s Processing triggers for man-db (2.12.0-3) ...
285s (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 ... 74271 files and directories currently installed.)
285s Purging configuration files for cloud-init (24.1-0ubuntu1) ...
286s dpkg: warning: while removing cloud-init, directory '/etc/cloud/cloud.cfg.d' not empty so not removed
286s Processing triggers for rsyslog (8.2312.0-3ubuntu3) ...
286s Reading package lists...
287s Building dependency tree...
287s Reading state information...
287s linux-generic is already the newest version (6.8.0-11.11+1).
287s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.
288s Hit:1 http://ftpmaster.internal/ubuntu noble InRelease
288s Hit:2 http://ftpmaster.internal/ubuntu noble-updates InRelease
288s Hit:3 http://ftpmaster.internal/ubuntu noble-security InRelease
289s Hit:4 http://ftpmaster.internal/ubuntu noble-proposed InRelease
291s Reading package lists...
291s Reading package lists...
291s Building dependency tree...
291s Reading state information...
292s Calculating upgrade...
293s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.
293s Reading package lists...
293s Building dependency tree...
293s Reading state information...
294s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.
294s autopkgtest [15:35:33]: rebooting testbed after setup commands that affected boot
320s autopkgtest [15:35:59]: testbed dpkg architecture: arm64
325s Reading package lists...
325s Building dependency tree...
325s Reading state information...
326s Correcting dependencies...Starting pkgProblemResolver with broken count: 0
326s Starting 2 pkgProblemResolver with broken count: 0
326s Done
326s  Done
326s Starting pkgProblemResolver with broken count: 0
327s Starting 2 pkgProblemResolver with broken count: 0
327s Done
327s The following additional packages will be installed:
327s   build-essential cpp cpp-13 cpp-13-aarch64-linux-gnu cpp-aarch64-linux-gnu
327s   g++ g++-13 g++-13-aarch64-linux-gnu g++-aarch64-linux-gnu gcc gcc-13
327s   gcc-13-aarch64-linux-gnu gcc-aarch64-linux-gnu libasan8 libatomic1 libblas3
327s   libc-dev-bin libc6-dev libcc1-0 libcrypt-dev libgcc-13-dev libgfortran5
327s   libgomp1 libhwasan0 libisl23 libitm1 liblapack3 liblsan0 libmpc3 libnsl-dev
327s   libpython3.11-minimal libpython3.11-stdlib libslow5-0 libslow5-dev
327s   libstdc++-13-dev libstreamvbyte-dev libstreamvbyte0 libtirpc-dev libtsan2
327s   libubsan1 linux-libc-dev python3-numpy python3-slow5 python3.11
327s   python3.11-minimal rpcsvc-proto zlib1g-dev
327s Suggested packages:
327s   cpp-doc gcc-13-locales cpp-13-doc gcc-13-doc gcc-multilib manpages-dev
327s   autoconf automake libtool flex bison gdb gcc-doc gdb-aarch64-linux-gnu
327s   glibc-doc libstdc++-13-doc gfortran python3-dev python3-pytest
327s   python3.11-venv python3.11-doc binfmt-support
327s Recommended packages:
327s   manpages manpages-dev libc-devtools
327s The following NEW packages will be installed:
327s   build-essential cpp cpp-13 cpp-13-aarch64-linux-gnu cpp-aarch64-linux-gnu
327s   g++ g++-13 g++-13-aarch64-linux-gnu g++-aarch64-linux-gnu gcc gcc-13
327s   gcc-13-aarch64-linux-gnu gcc-aarch64-linux-gnu libasan8 libatomic1 libblas3
327s   libc-dev-bin libc6-dev libcc1-0 libcrypt-dev libgcc-13-dev libgfortran5
327s   libgomp1 libhwasan0 libisl23 libitm1 liblapack3 liblsan0 libmpc3 libnsl-dev
327s   libpython3.11-minimal libpython3.11-stdlib libslow5-0 libslow5-dev
327s   libstdc++-13-dev libstreamvbyte-dev libstreamvbyte0 libtirpc-dev libtsan2
327s   libubsan1 linux-libc-dev python3-numpy python3-slow5 python3.11
327s   python3.11-minimal rpcsvc-proto zlib1g-dev
328s 0 upgraded, 47 newly installed, 0 to remove and 0 not upgraded.
328s 1 not fully installed or removed.
328s Need to get 76.2 MB of archives.
328s After this operation, 290 MB of additional disk space will be used.
328s Get:1 http://ftpmaster.internal/ubuntu noble/universe arm64 libslow5-0 arm64 0.7.0+dfsg-2ubuntu4 [61.3 kB]
328s Get:2 http://ftpmaster.internal/ubuntu noble/universe arm64 libslow5-dev arm64 0.7.0+dfsg-2ubuntu4 [90.0 kB]
328s Get:3 http://ftpmaster.internal/ubuntu noble/universe arm64 libstreamvbyte0 arm64 0.4.1-4ubuntu1 [6260 B]
328s Get:4 http://ftpmaster.internal/ubuntu noble/main arm64 libpython3.11-minimal arm64 3.11.8-1 [837 kB]
328s Get:5 http://ftpmaster.internal/ubuntu noble/main arm64 python3.11-minimal arm64 3.11.8-1 [2150 kB]
328s Get:6 http://ftpmaster.internal/ubuntu noble/main arm64 libpython3.11-stdlib arm64 3.11.8-1 [1913 kB]
328s Get:7 http://ftpmaster.internal/ubuntu noble/main arm64 python3.11 arm64 3.11.8-1 [589 kB]
328s Get:8 http://ftpmaster.internal/ubuntu noble/main arm64 libblas3 arm64 3.12.0-3 [143 kB]
328s Get:9 http://ftpmaster.internal/ubuntu noble/main arm64 libgfortran5 arm64 14-20240221-2.1ubuntu1 [443 kB]
328s Get:10 http://ftpmaster.internal/ubuntu noble/main arm64 liblapack3 arm64 3.12.0-3 [2241 kB]
328s Get:11 http://ftpmaster.internal/ubuntu noble/main arm64 python3-numpy arm64 1:1.24.2-2 [4525 kB]
328s Get:12 http://ftpmaster.internal/ubuntu noble/universe arm64 python3-slow5 arm64 0.7.0+dfsg-2ubuntu4 [610 kB]
328s Get:13 http://ftpmaster.internal/ubuntu noble/main arm64 libc-dev-bin arm64 2.39-0ubuntu2 [19.7 kB]
328s Get:14 http://ftpmaster.internal/ubuntu noble/main arm64 linux-libc-dev arm64 6.8.0-11.11 [1569 kB]
328s Get:15 http://ftpmaster.internal/ubuntu noble/main arm64 libcrypt-dev arm64 1:4.4.36-4 [136 kB]
328s Get:16 http://ftpmaster.internal/ubuntu noble/main arm64 libtirpc-dev arm64 1.3.4+ds-1build1 [232 kB]
328s Get:17 http://ftpmaster.internal/ubuntu noble/main arm64 libnsl-dev arm64 1.3.0-3 [71.9 kB]
328s Get:18 http://ftpmaster.internal/ubuntu noble/main arm64 rpcsvc-proto arm64 1.4.2-0ubuntu6 [65.4 kB]
328s Get:19 http://ftpmaster.internal/ubuntu noble/main arm64 libc6-dev arm64 2.39-0ubuntu2 [1596 kB]
328s Get:20 http://ftpmaster.internal/ubuntu noble/main arm64 libisl23 arm64 0.26-3 [713 kB]
328s Get:21 http://ftpmaster.internal/ubuntu noble/main arm64 libmpc3 arm64 1.3.1-1 [55.3 kB]
328s Get:22 http://ftpmaster.internal/ubuntu noble/main arm64 cpp-13-aarch64-linux-gnu arm64 13.2.0-17ubuntu2 [10.3 MB]
329s Get:23 http://ftpmaster.internal/ubuntu noble/main arm64 cpp-13 arm64 13.2.0-17ubuntu2 [1028 B]
329s Get:24 http://ftpmaster.internal/ubuntu noble/main arm64 cpp-aarch64-linux-gnu arm64 4:13.2.0-7ubuntu1 [5316 B]
329s Get:25 http://ftpmaster.internal/ubuntu noble/main arm64 cpp arm64 4:13.2.0-7ubuntu1 [22.4 kB]
329s Get:26 http://ftpmaster.internal/ubuntu noble/main arm64 libcc1-0 arm64 14-20240221-2.1ubuntu1 [44.9 kB]
329s Get:27 http://ftpmaster.internal/ubuntu noble/main arm64 libgomp1 arm64 14-20240221-2.1ubuntu1 [144 kB]
329s Get:28 http://ftpmaster.internal/ubuntu noble/main arm64 libitm1 arm64 14-20240221-2.1ubuntu1 [27.6 kB]
329s Get:29 http://ftpmaster.internal/ubuntu noble/main arm64 libatomic1 arm64 14-20240221-2.1ubuntu1 [11.4 kB]
329s Get:30 http://ftpmaster.internal/ubuntu noble/main arm64 libasan8 arm64 14-20240221-2.1ubuntu1 [2918 kB]
329s Get:31 http://ftpmaster.internal/ubuntu noble/main arm64 liblsan0 arm64 14-20240221-2.1ubuntu1 [1281 kB]
329s Get:32 http://ftpmaster.internal/ubuntu noble/main arm64 libtsan2 arm64 14-20240221-2.1ubuntu1 [2688 kB]
329s Get:33 http://ftpmaster.internal/ubuntu noble/main arm64 libubsan1 arm64 14-20240221-2.1ubuntu1 [1150 kB]
329s Get:34 http://ftpmaster.internal/ubuntu noble/main arm64 libhwasan0 arm64 14-20240221-2.1ubuntu1 [1597 kB]
329s Get:35 http://ftpmaster.internal/ubuntu noble/main arm64 libgcc-13-dev arm64 13.2.0-17ubuntu2 [2464 kB]
329s Get:36 http://ftpmaster.internal/ubuntu noble/main arm64 gcc-13-aarch64-linux-gnu arm64 13.2.0-17ubuntu2 [20.1 MB]
329s Get:37 http://ftpmaster.internal/ubuntu noble/main arm64 gcc-13 arm64 13.2.0-17ubuntu2 [467 kB]
329s Get:38 http://ftpmaster.internal/ubuntu noble/main arm64 gcc-aarch64-linux-gnu arm64 4:13.2.0-7ubuntu1 [1198 B]
329s Get:39 http://ftpmaster.internal/ubuntu noble/main arm64 gcc arm64 4:13.2.0-7ubuntu1 [5018 B]
329s Get:40 http://ftpmaster.internal/ubuntu noble/main arm64 libstdc++-13-dev arm64 13.2.0-17ubuntu2 [2322 kB]
329s Get:41 http://ftpmaster.internal/ubuntu noble/main arm64 g++-13-aarch64-linux-gnu arm64 13.2.0-17ubuntu2 [11.7 MB]
330s Get:42 http://ftpmaster.internal/ubuntu noble/main arm64 g++-13 arm64 13.2.0-17ubuntu2 [14.4 kB]
330s Get:43 http://ftpmaster.internal/ubuntu noble/main arm64 g++-aarch64-linux-gnu arm64 4:13.2.0-7ubuntu1 [962 B]
330s Get:44 http://ftpmaster.internal/ubuntu noble/main arm64 g++ arm64 4:13.2.0-7ubuntu1 [1082 B]
330s Get:45 http://ftpmaster.internal/ubuntu noble/main arm64 build-essential arm64 12.10ubuntu1 [4932 B]
330s Get:46 http://ftpmaster.internal/ubuntu noble-proposed/main arm64 zlib1g-dev arm64 1:1.3.dfsg-3.1ubuntu1 [894 kB]
330s Get:47 http://ftpmaster.internal/ubuntu noble/universe arm64 libstreamvbyte-dev arm64 0.4.1-4ubuntu1 [6620 B]
331s Fetched 76.2 MB in 2s (30.9 MB/s)
331s Selecting previously unselected package libslow5-0:arm64.
331s (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 ... 74216 files and directories currently installed.)
331s Preparing to unpack .../00-libslow5-0_0.7.0+dfsg-2ubuntu4_arm64.deb ...
331s Unpacking libslow5-0:arm64 (0.7.0+dfsg-2ubuntu4) ...
331s Selecting previously unselected package libslow5-dev:arm64.
331s Preparing to unpack .../01-libslow5-dev_0.7.0+dfsg-2ubuntu4_arm64.deb ...
331s Unpacking libslow5-dev:arm64 (0.7.0+dfsg-2ubuntu4) ...
331s Selecting previously unselected package libstreamvbyte0:arm64.
331s Preparing to unpack .../02-libstreamvbyte0_0.4.1-4ubuntu1_arm64.deb ...
331s Unpacking libstreamvbyte0:arm64 (0.4.1-4ubuntu1) ...
331s Selecting previously unselected package libpython3.11-minimal:arm64.
331s Preparing to unpack .../03-libpython3.11-minimal_3.11.8-1_arm64.deb ...
331s Unpacking libpython3.11-minimal:arm64 (3.11.8-1) ...
331s Selecting previously unselected package python3.11-minimal.
331s Preparing to unpack .../04-python3.11-minimal_3.11.8-1_arm64.deb ...
331s Unpacking python3.11-minimal (3.11.8-1) ...
331s Selecting previously unselected package libpython3.11-stdlib:arm64.
331s Preparing to unpack .../05-libpython3.11-stdlib_3.11.8-1_arm64.deb ...
331s Unpacking libpython3.11-stdlib:arm64 (3.11.8-1) ...
331s Selecting previously unselected package python3.11.
331s Preparing to unpack .../06-python3.11_3.11.8-1_arm64.deb ...
331s Unpacking python3.11 (3.11.8-1) ...
331s Selecting previously unselected package libblas3:arm64.
331s Preparing to unpack .../07-libblas3_3.12.0-3_arm64.deb ...
331s Unpacking libblas3:arm64 (3.12.0-3) ...
331s Selecting previously unselected package libgfortran5:arm64.
331s Preparing to unpack .../08-libgfortran5_14-20240221-2.1ubuntu1_arm64.deb ...
331s Unpacking libgfortran5:arm64 (14-20240221-2.1ubuntu1) ...
331s Selecting previously unselected package liblapack3:arm64.
331s Preparing to unpack .../09-liblapack3_3.12.0-3_arm64.deb ...
331s Unpacking liblapack3:arm64 (3.12.0-3) ...
331s Selecting previously unselected package python3-numpy.
331s Preparing to unpack .../10-python3-numpy_1%3a1.24.2-2_arm64.deb ...
331s Unpacking python3-numpy (1:1.24.2-2) ...
332s Selecting previously unselected package python3-slow5.
332s Preparing to unpack .../11-python3-slow5_0.7.0+dfsg-2ubuntu4_arm64.deb ...
332s Unpacking python3-slow5 (0.7.0+dfsg-2ubuntu4) ...
332s Selecting previously unselected package libc-dev-bin.
332s Preparing to unpack .../12-libc-dev-bin_2.39-0ubuntu2_arm64.deb ...
332s Unpacking libc-dev-bin (2.39-0ubuntu2) ...
332s Selecting previously unselected package linux-libc-dev:arm64.
332s Preparing to unpack .../13-linux-libc-dev_6.8.0-11.11_arm64.deb ...
332s Unpacking linux-libc-dev:arm64 (6.8.0-11.11) ...
332s Selecting previously unselected package libcrypt-dev:arm64.
332s Preparing to unpack .../14-libcrypt-dev_1%3a4.4.36-4_arm64.deb ...
332s Unpacking libcrypt-dev:arm64 (1:4.4.36-4) ...
332s Selecting previously unselected package libtirpc-dev:arm64.
332s Preparing to unpack .../15-libtirpc-dev_1.3.4+ds-1build1_arm64.deb ...
332s Unpacking libtirpc-dev:arm64 (1.3.4+ds-1build1) ...
332s Selecting previously unselected package libnsl-dev:arm64.
332s Preparing to unpack .../16-libnsl-dev_1.3.0-3_arm64.deb ...
332s Unpacking libnsl-dev:arm64 (1.3.0-3) ...
332s Selecting previously unselected package rpcsvc-proto.
332s Preparing to unpack .../17-rpcsvc-proto_1.4.2-0ubuntu6_arm64.deb ...
332s Unpacking rpcsvc-proto (1.4.2-0ubuntu6) ...
332s Selecting previously unselected package libc6-dev:arm64.
332s Preparing to unpack .../18-libc6-dev_2.39-0ubuntu2_arm64.deb ...
332s Unpacking libc6-dev:arm64 (2.39-0ubuntu2) ...
332s Selecting previously unselected package libisl23:arm64.
332s Preparing to unpack .../19-libisl23_0.26-3_arm64.deb ...
332s Unpacking libisl23:arm64 (0.26-3) ...
332s Selecting previously unselected package libmpc3:arm64.
332s Preparing to unpack .../20-libmpc3_1.3.1-1_arm64.deb ...
332s Unpacking libmpc3:arm64 (1.3.1-1) ...
332s Selecting previously unselected package cpp-13-aarch64-linux-gnu.
332s Preparing to unpack .../21-cpp-13-aarch64-linux-gnu_13.2.0-17ubuntu2_arm64.deb ...
332s Unpacking cpp-13-aarch64-linux-gnu (13.2.0-17ubuntu2) ...
332s Selecting previously unselected package cpp-13.
332s Preparing to unpack .../22-cpp-13_13.2.0-17ubuntu2_arm64.deb ...
332s Unpacking cpp-13 (13.2.0-17ubuntu2) ...
332s Selecting previously unselected package cpp-aarch64-linux-gnu.
332s Preparing to unpack .../23-cpp-aarch64-linux-gnu_4%3a13.2.0-7ubuntu1_arm64.deb ...
332s Unpacking cpp-aarch64-linux-gnu (4:13.2.0-7ubuntu1) ...
332s Selecting previously unselected package cpp.
332s Preparing to unpack .../24-cpp_4%3a13.2.0-7ubuntu1_arm64.deb ...
332s Unpacking cpp (4:13.2.0-7ubuntu1) ...
332s Selecting previously unselected package libcc1-0:arm64.
332s Preparing to unpack .../25-libcc1-0_14-20240221-2.1ubuntu1_arm64.deb ...
332s Unpacking libcc1-0:arm64 (14-20240221-2.1ubuntu1) ...
332s Selecting previously unselected package libgomp1:arm64.
333s Preparing to unpack .../26-libgomp1_14-20240221-2.1ubuntu1_arm64.deb ...
333s Unpacking libgomp1:arm64 (14-20240221-2.1ubuntu1) ...
333s Selecting previously unselected package libitm1:arm64.
333s Preparing to unpack .../27-libitm1_14-20240221-2.1ubuntu1_arm64.deb ...
333s Unpacking libitm1:arm64 (14-20240221-2.1ubuntu1) ...
333s Selecting previously unselected package libatomic1:arm64.
333s Preparing to unpack .../28-libatomic1_14-20240221-2.1ubuntu1_arm64.deb ...
333s Unpacking libatomic1:arm64 (14-20240221-2.1ubuntu1) ...
333s Selecting previously unselected package libasan8:arm64.
333s Preparing to unpack .../29-libasan8_14-20240221-2.1ubuntu1_arm64.deb ...
333s Unpacking libasan8:arm64 (14-20240221-2.1ubuntu1) ...
333s Selecting previously unselected package liblsan0:arm64.
333s Preparing to unpack .../30-liblsan0_14-20240221-2.1ubuntu1_arm64.deb ...
333s Unpacking liblsan0:arm64 (14-20240221-2.1ubuntu1) ...
333s Selecting previously unselected package libtsan2:arm64.
333s Preparing to unpack .../31-libtsan2_14-20240221-2.1ubuntu1_arm64.deb ...
333s Unpacking libtsan2:arm64 (14-20240221-2.1ubuntu1) ...
333s Selecting previously unselected package libubsan1:arm64.
333s Preparing to unpack .../32-libubsan1_14-20240221-2.1ubuntu1_arm64.deb ...
333s Unpacking libubsan1:arm64 (14-20240221-2.1ubuntu1) ...
333s Selecting previously unselected package libhwasan0:arm64.
333s Preparing to unpack .../33-libhwasan0_14-20240221-2.1ubuntu1_arm64.deb ...
333s Unpacking libhwasan0:arm64 (14-20240221-2.1ubuntu1) ...
333s Selecting previously unselected package libgcc-13-dev:arm64.
333s Preparing to unpack .../34-libgcc-13-dev_13.2.0-17ubuntu2_arm64.deb ...
333s Unpacking libgcc-13-dev:arm64 (13.2.0-17ubuntu2) ...
333s Selecting previously unselected package gcc-13-aarch64-linux-gnu.
333s Preparing to unpack .../35-gcc-13-aarch64-linux-gnu_13.2.0-17ubuntu2_arm64.deb ...
333s Unpacking gcc-13-aarch64-linux-gnu (13.2.0-17ubuntu2) ...
333s Selecting previously unselected package gcc-13.
333s Preparing to unpack .../36-gcc-13_13.2.0-17ubuntu2_arm64.deb ...
333s Unpacking gcc-13 (13.2.0-17ubuntu2) ...
333s Selecting previously unselected package gcc-aarch64-linux-gnu.
334s Preparing to unpack .../37-gcc-aarch64-linux-gnu_4%3a13.2.0-7ubuntu1_arm64.deb ...
334s Unpacking gcc-aarch64-linux-gnu (4:13.2.0-7ubuntu1) ...
334s Selecting previously unselected package gcc.
334s Preparing to unpack .../38-gcc_4%3a13.2.0-7ubuntu1_arm64.deb ...
334s Unpacking gcc (4:13.2.0-7ubuntu1) ...
334s Selecting previously unselected package libstdc++-13-dev:arm64.
334s Preparing to unpack .../39-libstdc++-13-dev_13.2.0-17ubuntu2_arm64.deb ...
334s Unpacking libstdc++-13-dev:arm64 (13.2.0-17ubuntu2) ...
334s Selecting previously unselected package g++-13-aarch64-linux-gnu.
334s Preparing to unpack .../40-g++-13-aarch64-linux-gnu_13.2.0-17ubuntu2_arm64.deb ...
334s Unpacking g++-13-aarch64-linux-gnu (13.2.0-17ubuntu2) ...
334s Selecting previously unselected package g++-13.
334s Preparing to unpack .../41-g++-13_13.2.0-17ubuntu2_arm64.deb ...
334s Unpacking g++-13 (13.2.0-17ubuntu2) ...
334s Selecting previously unselected package g++-aarch64-linux-gnu.
334s Preparing to unpack .../42-g++-aarch64-linux-gnu_4%3a13.2.0-7ubuntu1_arm64.deb ...
334s Unpacking g++-aarch64-linux-gnu (4:13.2.0-7ubuntu1) ...
334s Selecting previously unselected package g++.
334s Preparing to unpack .../43-g++_4%3a13.2.0-7ubuntu1_arm64.deb ...
334s Unpacking g++ (4:13.2.0-7ubuntu1) ...
334s Selecting previously unselected package build-essential.
334s Preparing to unpack .../44-build-essential_12.10ubuntu1_arm64.deb ...
334s Unpacking build-essential (12.10ubuntu1) ...
334s Selecting previously unselected package zlib1g-dev:arm64.
334s Preparing to unpack .../45-zlib1g-dev_1%3a1.3.dfsg-3.1ubuntu1_arm64.deb ...
334s Unpacking zlib1g-dev:arm64 (1:1.3.dfsg-3.1ubuntu1) ...
334s Selecting previously unselected package libstreamvbyte-dev:arm64.
334s Preparing to unpack .../46-libstreamvbyte-dev_0.4.1-4ubuntu1_arm64.deb ...
334s Unpacking libstreamvbyte-dev:arm64 (0.4.1-4ubuntu1) ...
334s Setting up libstreamvbyte0:arm64 (0.4.1-4ubuntu1) ...
334s Setting up linux-libc-dev:arm64 (6.8.0-11.11) ...
334s Setting up libgomp1:arm64 (14-20240221-2.1ubuntu1) ...
334s Setting up libblas3:arm64 (3.12.0-3) ...
334s update-alternatives: using /usr/lib/aarch64-linux-gnu/blas/libblas.so.3 to provide /usr/lib/aarch64-linux-gnu/libblas.so.3 (libblas.so.3-aarch64-linux-gnu) in auto mode
334s Setting up libtirpc-dev:arm64 (1.3.4+ds-1build1) ...
334s Setting up rpcsvc-proto (1.4.2-0ubuntu6) ...
334s Setting up libstreamvbyte-dev:arm64 (0.4.1-4ubuntu1) ...
334s Setting up libmpc3:arm64 (1.3.1-1) ...
334s Setting up libatomic1:arm64 (14-20240221-2.1ubuntu1) ...
334s Setting up libslow5-0:arm64 (0.7.0+dfsg-2ubuntu4) ...
334s Setting up libgfortran5:arm64 (14-20240221-2.1ubuntu1) ...
334s Setting up libubsan1:arm64 (14-20240221-2.1ubuntu1) ...
334s Setting up libnsl-dev:arm64 (1.3.0-3) ...
334s Setting up libhwasan0:arm64 (14-20240221-2.1ubuntu1) ...
334s Setting up libcrypt-dev:arm64 (1:4.4.36-4) ...
334s Setting up libasan8:arm64 (14-20240221-2.1ubuntu1) ...
334s Setting up libpython3.11-minimal:arm64 (3.11.8-1) ...
334s Setting up libtsan2:arm64 (14-20240221-2.1ubuntu1) ...
334s Setting up libisl23:arm64 (0.26-3) ...
334s Setting up libc-dev-bin (2.39-0ubuntu2) ...
334s Setting up libcc1-0:arm64 (14-20240221-2.1ubuntu1) ...
334s Setting up liblsan0:arm64 (14-20240221-2.1ubuntu1) ...
334s Setting up libitm1:arm64 (14-20240221-2.1ubuntu1) ...
334s Setting up python3.11-minimal (3.11.8-1) ...
335s Setting up liblapack3:arm64 (3.12.0-3) ...
335s update-alternatives: using /usr/lib/aarch64-linux-gnu/lapack/liblapack.so.3 to provide /usr/lib/aarch64-linux-gnu/liblapack.so.3 (liblapack.so.3-aarch64-linux-gnu) in auto mode
335s Setting up cpp-13-aarch64-linux-gnu (13.2.0-17ubuntu2) ...
335s Setting up libpython3.11-stdlib:arm64 (3.11.8-1) ...
335s Setting up libslow5-dev:arm64 (0.7.0+dfsg-2ubuntu4) ...
335s Setting up cpp-aarch64-linux-gnu (4:13.2.0-7ubuntu1) ...
335s Setting up libgcc-13-dev:arm64 (13.2.0-17ubuntu2) ...
335s Setting up libc6-dev:arm64 (2.39-0ubuntu2) ...
335s Setting up libstdc++-13-dev:arm64 (13.2.0-17ubuntu2) ...
335s Setting up python3.11 (3.11.8-1) ...
336s Setting up cpp-13 (13.2.0-17ubuntu2) ...
336s Setting up gcc-13-aarch64-linux-gnu (13.2.0-17ubuntu2) ...
336s Setting up gcc-13 (13.2.0-17ubuntu2) ...
336s Setting up python3-numpy (1:1.24.2-2) ...
337s Setting up zlib1g-dev:arm64 (1:1.3.dfsg-3.1ubuntu1) ...
337s Setting up cpp (4:13.2.0-7ubuntu1) ...
338s Setting up g++-13-aarch64-linux-gnu (13.2.0-17ubuntu2) ...
338s Setting up gcc-aarch64-linux-gnu (4:13.2.0-7ubuntu1) ...
338s Setting up g++-13 (13.2.0-17ubuntu2) ...
338s Setting up gcc (4:13.2.0-7ubuntu1) ...
338s Setting up python3-slow5 (0.7.0+dfsg-2ubuntu4) ...
338s Setting up g++-aarch64-linux-gnu (4:13.2.0-7ubuntu1) ...
338s Setting up g++ (4:13.2.0-7ubuntu1) ...
338s update-alternatives: using /usr/bin/g++ to provide /usr/bin/c++ (c++) in auto mode
338s Setting up build-essential (12.10ubuntu1) ...
338s Setting up autopkgtest-satdep (0) ...
338s Processing triggers for systemd (255.2-3ubuntu2) ...
338s Processing triggers for man-db (2.12.0-3) ...
339s Processing triggers for libc-bin (2.39-0ubuntu2) ...
342s (Reading database ... 78843 files and directories currently installed.)
342s Removing autopkgtest-satdep (0) ...
346s autopkgtest [15:36:25]: test run-pkg-test: [-----------------------
346s Checking unit_test_ascii.c
347s Done!
347s Checking unit_test_binary.c
347s Done!
347s Checking unit_test_empty.c
347s Done!
347s Checking unit_test_enum.c
347s Done!
347s Checking unit_test_helpers.c
350s Done!
350s Checking unit_test_lossless.c
350s autopkgtest [15:36:27]: test run-pkg-test: -----------------------]
350s Done!
350s Checking unit_test_press.c
350s Done!
350s Checking unit_test_two_rg.c
350s Done!
351s run-pkg-test         PASS
351s autopkgtest [15:36:30]: test run-pkg-test:  - - - - - - - - - - results - - - - - - - - - -
351s autopkgtest [15:36:30]: @@@@@@@@@@@@@@@@@@@@ summary
351s run-pybinding-test   PASS
351s run-pkg-test         PASS
366s Creating nova instance adt-noble-arm64-libslow5lib-20240305-153039-juju-7f2275-prod-proposed-migration-environment-3 from image adt/ubuntu-noble-arm64-server-20240305.img (UUID 1a8a2f7d-2f12-433c-87a5-93dadd986985)...
366s Creating nova instance adt-noble-arm64-libslow5lib-20240305-153039-juju-7f2275-prod-proposed-migration-environment-3 from image adt/ubuntu-noble-arm64-server-20240305.img (UUID 1a8a2f7d-2f12-433c-87a5-93dadd986985)...