0s autopkgtest [22:46:17]: starting date and time: 2024-07-12 22:46:17+0000
  0s autopkgtest [22:46:17]: git checkout: fd3bed09 nova: allow more retries for quota issues
  0s autopkgtest [22:46:17]: host juju-7f2275-prod-proposed-migration-environment-9; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work._x9su6hu/out --timeout-copy=6000 --setup-commands 'ln -s /dev/null /etc/systemd/system/bluetooth.service; printf "http_proxy=http://squid.internal:3128\nhttps_proxy=http://squid.internal:3128\nno_proxy=127.0.0.1,127.0.1.1,login.ubuntu.com,localhost,localdomain,novalocal,internal,archive.ubuntu.com,ports.ubuntu.com,security.ubuntu.com,ddebs.ubuntu.com,changelogs.ubuntu.com,keyserver.ubuntu.com,launchpadlibrarian.net,launchpadcontent.net,launchpad.net,10.24.0.0/24,keystone.ps5.canonical.com,objectstorage.prodstack5.canonical.com\n" >> /etc/environment' --apt-pocket=proposed=src:glibc --apt-upgrade libslow5lib --timeout-short=300 --timeout-copy=20000 --timeout-build=20000 --env=ADT_TEST_TRIGGERS=glibc/2.39-3.1ubuntu3 -- lxd -r lxd-armhf-10.145.243.242 lxd-armhf-10.145.243.242:autopkgtest/ubuntu/oracular/armhf
 55s autopkgtest [22:47:12]: testbed dpkg architecture: armhf
 57s autopkgtest [22:47:14]: testbed apt version: 2.9.6
 57s autopkgtest [22:47:14]: @@@@@@@@@@@@@@@@@@@@ test bed setup
 64s Get:1 http://ftpmaster.internal/ubuntu oracular-proposed InRelease [126 kB]
 65s Get:2 http://ftpmaster.internal/ubuntu oracular-proposed/main Sources [46.5 kB]
 65s Get:3 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse Sources [3288 B]
 65s Get:4 http://ftpmaster.internal/ubuntu oracular-proposed/restricted Sources [8548 B]
 65s Get:5 http://ftpmaster.internal/ubuntu oracular-proposed/universe Sources [360 kB]
 65s Get:6 http://ftpmaster.internal/ubuntu oracular-proposed/main armhf Packages [57.9 kB]
 65s Get:7 http://ftpmaster.internal/ubuntu oracular-proposed/main armhf c-n-f Metadata [1440 B]
 65s Get:8 http://ftpmaster.internal/ubuntu oracular-proposed/restricted armhf Packages [1368 B]
 65s Get:9 http://ftpmaster.internal/ubuntu oracular-proposed/restricted armhf c-n-f Metadata [120 B]
 65s Get:10 http://ftpmaster.internal/ubuntu oracular-proposed/universe armhf Packages [309 kB]
 65s Get:11 http://ftpmaster.internal/ubuntu oracular-proposed/universe armhf c-n-f Metadata [6960 B]
 65s Get:12 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse armhf Packages [1796 B]
 65s Get:13 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse armhf c-n-f Metadata [120 B]
 67s Fetched 922 kB in 1s (1092 kB/s)
 67s Reading package lists...
 84s tee: /proc/self/fd/2: Permission denied
106s Hit:1 http://ftpmaster.internal/ubuntu oracular-proposed InRelease
106s Hit:2 http://ftpmaster.internal/ubuntu oracular InRelease
106s Hit:3 http://ftpmaster.internal/ubuntu oracular-updates InRelease
106s Hit:4 http://ftpmaster.internal/ubuntu oracular-security InRelease
107s Reading package lists...
107s Reading package lists...
108s Building dependency tree...
108s Reading state information...
108s Calculating upgrade...
108s The following packages will be upgraded:
108s   inetutils-telnet libc-bin libc6 libssl3t64 locales openssh-client
108s   openssh-server openssh-sftp-server openssl telnet
109s 10 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.
109s Need to get 11.9 MB of archives.
109s After this operation, 285 kB of additional disk space will be used.
109s Get:1 http://ftpmaster.internal/ubuntu oracular-proposed/main armhf libc6 armhf 2.39-3.1ubuntu3 [2825 kB]
109s Get:2 http://ftpmaster.internal/ubuntu oracular-proposed/main armhf libc-bin armhf 2.39-3.1ubuntu3 [527 kB]
109s Get:3 http://ftpmaster.internal/ubuntu oracular/main armhf libssl3t64 armhf 3.2.2-1ubuntu1 [1729 kB]
109s Get:4 http://ftpmaster.internal/ubuntu oracular/main armhf openssh-sftp-server armhf 1:9.6p1-3ubuntu17 [35.6 kB]
109s Get:5 http://ftpmaster.internal/ubuntu oracular/main armhf openssh-server armhf 1:9.6p1-3ubuntu17 [502 kB]
109s Get:6 http://ftpmaster.internal/ubuntu oracular/main armhf openssh-client armhf 1:9.6p1-3ubuntu17 [888 kB]
109s Get:7 http://ftpmaster.internal/ubuntu oracular-proposed/main armhf locales all 2.39-3.1ubuntu3 [4220 kB]
109s Get:8 http://ftpmaster.internal/ubuntu oracular/main armhf openssl armhf 3.2.2-1ubuntu1 [1095 kB]
109s Get:9 http://ftpmaster.internal/ubuntu oracular/main armhf inetutils-telnet armhf 2:2.5-5ubuntu1 [94.4 kB]
109s Get:10 http://ftpmaster.internal/ubuntu oracular/main armhf telnet all 0.17+2.5-5ubuntu1 [3688 B]
110s Preconfiguring packages ...
110s Fetched 11.9 MB in 1s (13.1 MB/s)
110s (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 ... 58437 files and directories currently installed.)
110s Preparing to unpack .../libc6_2.39-3.1ubuntu3_armhf.deb ...
110s Unpacking libc6:armhf (2.39-3.1ubuntu3) over (2.39-0ubuntu9) ...
110s Setting up libc6:armhf (2.39-3.1ubuntu3) ...
110s Error: Could not restart systemd, systemd binary not working
110s (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 ... 58437 files and directories currently installed.)
110s Preparing to unpack .../libc-bin_2.39-3.1ubuntu3_armhf.deb ...
110s Unpacking libc-bin (2.39-3.1ubuntu3) over (2.39-0ubuntu9) ...
110s Setting up libc-bin (2.39-3.1ubuntu3) ...
111s (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 ... 58437 files and directories currently installed.)
111s Preparing to unpack .../libssl3t64_3.2.2-1ubuntu1_armhf.deb ...
111s Unpacking libssl3t64:armhf (3.2.2-1ubuntu1) over (3.2.1-3ubuntu1) ...
111s Setting up libssl3t64:armhf (3.2.2-1ubuntu1) ...
111s (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 ... 58437 files and directories currently installed.)
111s Preparing to unpack .../0-openssh-sftp-server_1%3a9.6p1-3ubuntu17_armhf.deb ...
111s Unpacking openssh-sftp-server (1:9.6p1-3ubuntu17) over (1:9.6p1-3ubuntu15) ...
111s Preparing to unpack .../1-openssh-server_1%3a9.6p1-3ubuntu17_armhf.deb ...
111s Unpacking openssh-server (1:9.6p1-3ubuntu17) over (1:9.6p1-3ubuntu15) ...
111s Preparing to unpack .../2-openssh-client_1%3a9.6p1-3ubuntu17_armhf.deb ...
111s Unpacking openssh-client (1:9.6p1-3ubuntu17) over (1:9.6p1-3ubuntu15) ...
111s Preparing to unpack .../3-locales_2.39-3.1ubuntu3_all.deb ...
111s Unpacking locales (2.39-3.1ubuntu3) over (2.39-0ubuntu9) ...
111s Preparing to unpack .../4-openssl_3.2.2-1ubuntu1_armhf.deb ...
111s Unpacking openssl (3.2.2-1ubuntu1) over (3.2.1-3ubuntu1) ...
112s Preparing to unpack .../5-inetutils-telnet_2%3a2.5-5ubuntu1_armhf.deb ...
112s Unpacking inetutils-telnet (2:2.5-5ubuntu1) over (2:2.5-3ubuntu4) ...
112s Preparing to unpack .../6-telnet_0.17+2.5-5ubuntu1_all.deb ...
112s Unpacking telnet (0.17+2.5-5ubuntu1) over (0.17+2.5-3ubuntu4) ...
112s Setting up openssh-client (1:9.6p1-3ubuntu17) ...
112s Setting up inetutils-telnet (2:2.5-5ubuntu1) ...
112s Setting up locales (2.39-3.1ubuntu3) ...
112s Generating locales (this might take a while)...
114s   en_US.UTF-8... done
114s Generation complete.
114s Setting up openssl (3.2.2-1ubuntu1) ...
114s Installing new version of config file /etc/ssl/openssl.cnf ...
114s Setting up openssh-sftp-server (1:9.6p1-3ubuntu17) ...
114s Setting up telnet (0.17+2.5-5ubuntu1) ...
114s Setting up openssh-server (1:9.6p1-3ubuntu17) ...
114s Installing new version of config file /etc/pam.d/sshd ...
115s Processing triggers for ufw (0.36.2-6) ...
115s Processing triggers for systemd (256-1ubuntu1) ...
116s Processing triggers for man-db (2.12.1-2) ...
117s Processing triggers for libc-bin (2.39-3.1ubuntu3) ...
117s Reading package lists...
117s Building dependency tree...
117s Reading state information...
118s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.
120s autopkgtest [22:48:17]: rebooting testbed after setup commands that affected boot
187s autopkgtest [22:49:24]: testbed running kernel: Linux 6.5.0-41-generic #41~22.04.2-Ubuntu SMP PREEMPT_DYNAMIC Mon Jun  3 16:28:24 UTC 2
215s autopkgtest [22:49:52]: @@@@@@@@@@@@@@@@@@@@ apt-source libslow5lib
233s Get:1 http://ftpmaster.internal/ubuntu oracular/universe libslow5lib 0.7.0+dfsg-2.1build1 (dsc) [2541 B]
233s Get:2 http://ftpmaster.internal/ubuntu oracular/universe libslow5lib 0.7.0+dfsg-2.1build1 (tar) [2014 kB]
233s Get:3 http://ftpmaster.internal/ubuntu oracular/universe libslow5lib 0.7.0+dfsg-2.1build1 (diff) [8280 B]
233s gpgv: Signature made Sun Mar 31 19:37:54 2024 UTC
233s gpgv:                using RSA key AC483F68DE728F43F2202FCA568D30F321B2133D
233s gpgv:                issuer "steve.langasek@ubuntu.com"
233s gpgv: Can't check signature: No public key
233s dpkg-source: warning: cannot verify inline signature for ./libslow5lib_0.7.0+dfsg-2.1build1.dsc: no acceptable signature found
234s autopkgtest [22:50:11]: testing package libslow5lib version 0.7.0+dfsg-2.1build1
236s autopkgtest [22:50:13]: build not needed
239s autopkgtest [22:50:16]: test run-pybinding-test: preparing testbed
249s Reading package lists...
249s Building dependency tree...
249s Reading state information...
250s Starting pkgProblemResolver with broken count: 0
250s Starting 2 pkgProblemResolver with broken count: 0
250s Done
250s The following additional packages will be installed:
250s   libblas3 libgfortran5 liblapack3 libslow5-0t64 libslow5-dev libstreamvbyte0
250s   python3-all python3-numpy python3-slow5
250s Suggested packages:
250s   gcc gfortran python-numpy-doc python3-dev python3-pytest
250s The following NEW packages will be installed:
250s   autopkgtest-satdep libblas3 libgfortran5 liblapack3 libslow5-0t64
250s   libslow5-dev libstreamvbyte0 python3-all python3-numpy python3-slow5
251s 0 upgraded, 10 newly installed, 0 to remove and 0 not upgraded.
251s Need to get 6675 kB/6675 kB of archives.
251s After this operation, 29.6 MB of additional disk space will be used.
251s Get:1 /tmp/autopkgtest.HDZm8r/1-autopkgtest-satdep.deb autopkgtest-satdep armhf 0 [728 B]
251s Get:2 http://ftpmaster.internal/ubuntu oracular/main armhf libblas3 armhf 3.12.0-3build1 [123 kB]
251s Get:3 http://ftpmaster.internal/ubuntu oracular/main armhf libgfortran5 armhf 14.1.0-1ubuntu1 [311 kB]
251s Get:4 http://ftpmaster.internal/ubuntu oracular/main armhf liblapack3 armhf 3.12.0-3build1 [2085 kB]
251s Get:5 http://ftpmaster.internal/ubuntu oracular/universe armhf libslow5-0t64 armhf 0.7.0+dfsg-2.1build1 [63.0 kB]
251s Get:6 http://ftpmaster.internal/ubuntu oracular/universe armhf libslow5-dev armhf 0.7.0+dfsg-2.1build1 [84.4 kB]
251s Get:7 http://ftpmaster.internal/ubuntu oracular/universe armhf libstreamvbyte0 armhf 0.4.1-4ubuntu1 [5742 B]
251s Get:8 http://ftpmaster.internal/ubuntu oracular/main armhf python3-all armhf 3.12.3-0ubuntu1 [886 B]
251s Get:9 http://ftpmaster.internal/ubuntu oracular/main armhf python3-numpy armhf 1:1.26.4+ds-10 [3541 kB]
251s Get:10 http://ftpmaster.internal/ubuntu oracular/universe armhf python3-slow5 armhf 0.7.0+dfsg-2.1build1 [460 kB]
252s Fetched 6675 kB in 1s (7725 kB/s)
252s Selecting previously unselected package libblas3:armhf.
252s (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 ... 58436 files and directories currently installed.)
252s Preparing to unpack .../0-libblas3_3.12.0-3build1_armhf.deb ...
252s Unpacking libblas3:armhf (3.12.0-3build1) ...
252s Selecting previously unselected package libgfortran5:armhf.
252s Preparing to unpack .../1-libgfortran5_14.1.0-1ubuntu1_armhf.deb ...
252s Unpacking libgfortran5:armhf (14.1.0-1ubuntu1) ...
252s Selecting previously unselected package liblapack3:armhf.
252s Preparing to unpack .../2-liblapack3_3.12.0-3build1_armhf.deb ...
252s Unpacking liblapack3:armhf (3.12.0-3build1) ...
252s Selecting previously unselected package libslow5-0t64:armhf.
252s Preparing to unpack .../3-libslow5-0t64_0.7.0+dfsg-2.1build1_armhf.deb ...
252s Unpacking libslow5-0t64:armhf (0.7.0+dfsg-2.1build1) ...
252s Selecting previously unselected package libslow5-dev:armhf.
252s Preparing to unpack .../4-libslow5-dev_0.7.0+dfsg-2.1build1_armhf.deb ...
252s Unpacking libslow5-dev:armhf (0.7.0+dfsg-2.1build1) ...
252s Selecting previously unselected package libstreamvbyte0:armhf.
252s Preparing to unpack .../5-libstreamvbyte0_0.4.1-4ubuntu1_armhf.deb ...
252s Unpacking libstreamvbyte0:armhf (0.4.1-4ubuntu1) ...
252s Selecting previously unselected package python3-all.
252s Preparing to unpack .../6-python3-all_3.12.3-0ubuntu1_armhf.deb ...
252s Unpacking python3-all (3.12.3-0ubuntu1) ...
252s Selecting previously unselected package python3-numpy.
252s Preparing to unpack .../7-python3-numpy_1%3a1.26.4+ds-10_armhf.deb ...
252s Unpacking python3-numpy (1:1.26.4+ds-10) ...
252s Selecting previously unselected package python3-slow5.
252s Preparing to unpack .../8-python3-slow5_0.7.0+dfsg-2.1build1_armhf.deb ...
252s Unpacking python3-slow5 (0.7.0+dfsg-2.1build1) ...
252s Selecting previously unselected package autopkgtest-satdep.
252s Preparing to unpack .../9-1-autopkgtest-satdep.deb ...
252s Unpacking autopkgtest-satdep (0) ...
252s Setting up libstreamvbyte0:armhf (0.4.1-4ubuntu1) ...
252s Setting up python3-all (3.12.3-0ubuntu1) ...
252s Setting up libblas3:armhf (3.12.0-3build1) ...
252s update-alternatives: using /usr/lib/arm-linux-gnueabihf/blas/libblas.so.3 to provide /usr/lib/arm-linux-gnueabihf/libblas.so.3 (libblas.so.3-arm-linux-gnueabihf) in auto mode
252s Setting up libslow5-0t64:armhf (0.7.0+dfsg-2.1build1) ...
252s Setting up libgfortran5:armhf (14.1.0-1ubuntu1) ...
252s Setting up liblapack3:armhf (3.12.0-3build1) ...
252s update-alternatives: using /usr/lib/arm-linux-gnueabihf/lapack/liblapack.so.3 to provide /usr/lib/arm-linux-gnueabihf/liblapack.so.3 (liblapack.so.3-arm-linux-gnueabihf) in auto mode
252s Setting up libslow5-dev:armhf (0.7.0+dfsg-2.1build1) ...
252s Setting up python3-numpy (1:1.26.4+ds-10) ...
254s Setting up python3-slow5 (0.7.0+dfsg-2.1build1) ...
254s Setting up autopkgtest-satdep (0) ...
254s Processing triggers for man-db (2.12.1-2) ...
255s Processing triggers for libc-bin (2.39-3.1ubuntu3) ...
271s (Reading database ... 59374 files and directories currently installed.)
271s Removing autopkgtest-satdep (0) ...
277s autopkgtest [22:50:54]: test run-pybinding-test: [-----------------------
279s Testing with python3.12 in /tmp/autopkgtest.HDZm8r/autopkgtest_tmp:
279s 12-Jul-24 22:50:56 - [DEBUG]: FILE: examples/example.slow5, mode: r
279s 12-Jul-24 22:50:56 - [DEBUG]: FILE: b'examples/example.slow5', mode: b'r'
279s 12-Jul-24 22:50:56 - [DEBUG]: Number of read_groups: 1
279s 12-Jul-24 22:50:56 - [DEBUG]: FILE: examples/example.slow5, mode: r
279s 12-Jul-24 22:50:56 - [DEBUG]: Creating/loading index...
279s [slow5_idx_init::INFO] Index file not found. Creating an index at 'examples/example.slow5.idx'.
279s 12-Jul-24 22:50:56 - [DEBUG]: get_aux_names starting
279s 12-Jul-24 22:50:56 - [DEBUG]: get_aux_names aux_len: 0
279s 12-Jul-24 22:50:56 - [WARNING]: get_aux_names ret is NULL
279s 12-Jul-24 22:50:56 - [DEBUG]: get_aux_types starting
279s 12-Jul-24 22:50:56 - [DEBUG]: get_aux_types aux_len: 0
279s 12-Jul-24 22:50:56 - [WARNING]: get_aux_types self.s5_aux_type is NULL
279s 12-Jul-24 22:50:56 - [WARNING]: get_read unknown aux name: read_number
279s 12-Jul-24 22:50:56 - [WARNING]: get_read unknown aux name: blah
279s 12-Jul-24 22:50:56 - [WARNING]: get_read unknown aux name: start_mux
280s 12-Jul-24 22:50:56 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:56 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:56 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:56 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:56 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:56 - [DEBUG]: slow5_get_next return: -1
280s 12-Jul-24 22:50:56 - [DEBUG]: slow5_get_next reached end of file (EOF)(-1): -1: ['SLOW5_ERR_EOF', 'End Of File reached']
280s [slow5_idx_get::ERROR] Read ID 'null_read' was not found. At src/slow5_idx.c:441
280s 12-Jul-24 22:50:56 - [DEBUG]: get_read return not 0: -7
280s 12-Jul-24 22:50:56 - [DEBUG]: slow5_get_hdr_keys head_len: 32
280s 12-Jul-24 22:50:56 - [DEBUG]: slow5_get_hdr_keys head_len: 32
280s 12-Jul-24 22:50:56 - [DEBUG]: examples/example.slow5 closed
280s 12-Jul-24 22:50:56 - [DEBUG]: FILE: examples/example2.slow5, mode: r
280s 12-Jul-24 22:50:56 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r'
280s 12-Jul-24 22:50:56 - [DEBUG]: Number of read_groups: 4
280s 12-Jul-24 22:50:56 - [DEBUG]: FILE: examples/example2.slow5, mode: r
280s 12-Jul-24 22:50:56 - [DEBUG]: Creating/loading index...
280s [slow5_idx_init::INFO] Index file not found. Creating an index at 'examples/example2.slow5.idx'.
280s 12-Jul-24 22:50:56 - [DEBUG]: get_aux_names starting
280s 12-Jul-24 22:50:56 - [DEBUG]: get_aux_names aux_len: 5
280s 12-Jul-24 22:50:56 - [DEBUG]: get_aux_types starting
280s 12-Jul-24 22:50:56 - [DEBUG]: get_aux_types aux_len: 5
280s 12-Jul-24 22:50:56 - [WARNING]: get_read unknown aux name: blah
280s 12-Jul-24 22:50:56 - [WARNING]: get_read unknown aux name: blah
280s 12-Jul-24 22:50:56 - [DEBUG]: get_aux_names starting
280s 12-Jul-24 22:50:56 - [DEBUG]: get_aux_names aux_len: 5
280s 12-Jul-24 22:50:56 - [DEBUG]: get_aux_types starting
280s 12-Jul-24 22:50:56 - [DEBUG]: get_aux_types aux_len: 5
280s 12-Jul-24 22:50:56 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:56 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:56 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:56 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:56 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:56 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: -1
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next reached end of file (EOF)(-1): -1: ['SLOW5_ERR_EOF', 'End Of File reached']
280s 12-Jul-24 22:50:57 - [DEBUG]: examples/example2.slow5 closed
280s 12-Jul-24 22:50:57 - [DEBUG]: FILE: examples/example_write.slow5, mode: w
280s 12-Jul-24 22:50:57 - [DEBUG]: FILE: b'examples/example_write.slow5', mode: b'w'
280s 12-Jul-24 22:50:57 - [DEBUG]: Not writing blow5, skipping compression steps
280s 12-Jul-24 22:50:57 - [DEBUG]: FILE: examples/example2.slow5, mode: r
280s 12-Jul-24 22:50:57 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r'
280s 12-Jul-24 22:50:57 - [DEBUG]: Number of read_groups: 4
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation running
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checking header stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: writting header...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: header written
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write() ret: 305872
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_free()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: function complete, returning 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation running
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write() ret: 152707
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_free()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: function complete, returning 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation running
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write() ret: 305872
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_free()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: function complete, returning 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation running
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write() ret: 152707
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_free()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: function complete, returning 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation running
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write() ret: 305872
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_free()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: function complete, returning 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation running
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write() ret: 152707
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_free()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: function complete, returning 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation running
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write() ret: 305906
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_free()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: function complete, returning 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation running
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write() ret: 152741
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_free()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: function complete, returning 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: -1
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next reached end of file (EOF)(-1): -1: ['SLOW5_ERR_EOF', 'End Of File reached']
280s 12-Jul-24 22:50:57 - [DEBUG]: examples/example_write.slow5 closed
280s 12-Jul-24 22:50:57 - [DEBUG]: examples/example2.slow5 closed
280s 12-Jul-24 22:50:57 - [DEBUG]: FILE: examples/example_write_append.blow5, mode: w
280s 12-Jul-24 22:50:57 - [DEBUG]: FILE: b'examples/example_write_append.blow5', mode: b'w'
280s 12-Jul-24 22:50:57 - [DEBUG]: examples/example_write.slow5 already closed
280s 12-Jul-24 22:50:57 - [DEBUG]: pathname: examples/example_write.slow5
280s 12-Jul-24 22:50:57 - [DEBUG]: total_time_slow5_get_next: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_time_yield_reads: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_single_write_time: 0.02872490882873535 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_multi_write_time: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: FILE: examples/example2.slow5, mode: r
280s 12-Jul-24 22:50:57 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r'
280s 12-Jul-24 22:50:57 - [DEBUG]: Number of read_groups: 4
280s 12-Jul-24 22:50:57 - [DEBUG]: pathname: examples/example2.slow5
280s 12-Jul-24 22:50:57 - [DEBUG]: total_time_slow5_get_next: 0.021848201751708984 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_time_yield_reads: 0.022751808166503906 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_single_write_time: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_multi_write_time: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation running
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checking header stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: writting header...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: header written
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write() ret: 152976
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_free()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: function complete, returning 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation running
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write() ret: 76384
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_free()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: function complete, returning 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation running
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write() ret: 152976
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_free()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: function complete, returning 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation running
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write() ret: 76384
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_free()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: function complete, returning 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation running
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write() ret: 152976
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_free()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: function complete, returning 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation running
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write() ret: 76384
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_free()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: function complete, returning 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation running
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write() ret: 153010
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_free()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: function complete, returning 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation running
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write() ret: 76418
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_free()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: function complete, returning 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: -1
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next reached end of file (EOF)(-1): -1: ['SLOW5_ERR_EOF', 'End Of File reached']
280s 12-Jul-24 22:50:57 - [DEBUG]: examples/example2.slow5 closed
280s 12-Jul-24 22:50:57 - [DEBUG]: examples/example_write_append.blow5 closed
280s 12-Jul-24 22:50:57 - [DEBUG]: FILE: examples/example_write_append.blow5, mode: a
280s 12-Jul-24 22:50:57 - [DEBUG]: FILE: b'examples/example_write_append.blow5', mode: b'a'
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_hdr_keys head_len: 38
280s 12-Jul-24 22:50:57 - [DEBUG]: FILE: examples/example2.slow5, mode: r
280s 12-Jul-24 22:50:57 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r'
280s 12-Jul-24 22:50:57 - [DEBUG]: Number of read_groups: 4
280s 12-Jul-24 22:50:57 - [DEBUG]: pathname: examples/example2.slow5
280s 12-Jul-24 22:50:57 - [DEBUG]: total_time_slow5_get_next: 0.02219414710998535 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_time_yield_reads: 0.02311849594116211 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_single_write_time: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_multi_write_time: 0.0 seconds
280s |==============================================|
280s |             pyslow5 test launch              |
280s |==============================================|
280s ['__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']
280s slow5 file opened and object created in: 0.0011 seconds
280s ==============================================
280s get_read check, r1
280s get_read in: 0.0042 seconds
280s read_id: r1
280s read_group: 0
280s digitisation: 8192.0
280s offset: 23.0
280s range: 1467.61
280s sampling_rate: 4000.0
280s len_raw_signal: 59676
280s signal: [1039  588  588  593  586  574  570  585  588  586]
280s pylen of signal: 59676
280s AUX FIELDS:
280s read_number: None
280s start_mux: None
280s blah: None
280s ==============================================
280s get_read check, r4, converte to pA
280s get_read in: 0.0042 seconds
280s read_id: r4
280s read_group: 0
280s digitisation: 8192.0
280s offset: 23.0
280s range: 1467.61
280s sampling_rate: 4000.0
280s len_raw_signal: 59670
280s signal: [190.25902  108.92418  109.46163  109.10333  107.67012  108.38673
280s  108.745026 109.10333  111.074    108.38673 ]
280s pylen of signal: 59670
280s signal value type: <class 'numpy.float32'>
280s ==============================================
280s seq_reads check, all reads
280s seq_reads readIDs:
280s type check reads: <class '_cython_3_0_8.generator'>
280s r1
280s r2
280s r3
280s r4
280s r5
280s seq_reads in: 0.0151 seconds
280s ==============================================
280s Yield check, selected reads
280s get_read_list in: 0.0 seconds
280s yielded readIDs:
280s r1 r1
280s r3 r3
280s null_read read not found, None returned
280s r5 r5
280s r2 r2
280s r1 r1
280s ==============================================
280s Get headder names
280s header names:
280s ['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']
280s ==============================================
280s get_all_headers
280s {'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'}
280s ==============================================
280s Get headder attributes
280s flow_cell_id: FAB43577
280s exp_start_time: 1479433093
280s heatsink_temp: 33.9921875
280s asic_id: 3574887596
280s asic_id_eeprom: 0
280s asic_temp: 29.2145729
280s auto_update: 1
280s auto_update_source: https://mirror.oxfordnanoportal.com/software/MinKNOW/
280s bream_core_version: 1.1.20.1
280s bream_is_standard: 1
280s bream_map_version: 1.1.20.1
280s bream_ont_version: 1.1.20.1
280s bream_prod_version: 1.1.20.1
280s bream_rnd_version: 0.1.1
280s device_id: MN16450
280s exp_script_name: python/recipes/nc/NC_48Hr_Sequencing_Run_FLO-MIN106_SQK-LSK108.py
280s exp_script_purpose: sequencing_run
280s exp_start_time: 1479433093
280s experiment_kit: genomic_dna
280s experiment_type: customer_qc
280s file_version: 1
280s filename: deamernanopore_20161117_fnfab43577_mn16450_sequencing_run_ma_821_r9_4_na12878_11_17_16_88738
280s flow_cell_id: FAB43577
280s heatsink_temp: 33.9921875
280s hostname: DEAMERNANOPORE
280s installation_type: map
280s local_firmware_file: 0
280s operating_system: Windows 6.2
280s protocol_run_id: a4429838-103c-497f-a824-7dffa72cfd81
280s protocols_version: 1.1.20
280s run_id: d6e473a6d513ec6bfc150c60fd4556d72f0e6d18
280s sample_frequency: 4000
280s usb_config: 1.0.11_ONT#MinION_fpga_1.0.1#ctrl#Auto
280s user_filename_input: ma_821_r9.4_na12878_11_17_16
280s version: 1.1.20
280s ==============================================
280s get_read check, 0d624d4b-671f-40b8-9798-84f2ccc4d7fc
280s read_id: 0d624d4b-671f-40b8-9798-84f2ccc4d7fc
280s read_group: 3
280s digitisation: 8192.0
280s offset: 6.0
280s range: 1444.86
280s sampling_rate: 4000.0
280s len_raw_signal: 38164
280s signal: [1462 1075  795  801  797  788  817  791  801  802]
280s pylen of signal: 38164
280s AUX FIELDS:
280s read_number: 2287
280s start_mux: 2
280s blah: None
280s AUX FIELDS:
280s blah: None
280s AUX FIELDS:
280s read_number: 2287
280s ==============================================
280s Get aux names
280s aux names:
280s ['channel_number', 'median_before', 'read_number', 'start_mux', 'start_time']
280s ==============================================
280s Get aux types
280s aux types:
280s [22, 9, 2, 4, 7]
280s ==============================================
280s AUX FIELDS:
280s channel_number: 391
280s median_before: 260.557264
280s read_number: 2287
280s start_mux: 2
280s start_time: 36886851
280s ==============================================
280s seq_reads with aux:
280s type check reads: <class '_cython_3_0_8.generator'>
280s r0
280s read_number 4019
280s r1
280s read_number 2287
280s r2
280s read_number 4019
280s r3
280s read_number 2287
280s r4
280s read_number 4019
280s r5
280s read_number 2287
280s 0a238451-b9ed-446d-a152-badd074006c4
280s read_number 4019
280s 0d624d4b-671f-40b8-9798-84f2ccc4d7fc
280s read_number 2287
280s ==============================================
280s write reads no aux
280s ret: write_header(): 0
280s ret: write_record(): 0
280s ret: write_record(): 0
280s ret: write_record(): 0
280s ret: write_record(): 0
280s ret: write_record(): 0
280s ret: write_record(): 0
280s ret: write_record(): 0
280s ret: write_record(): 0
280s ==============================================
280s append reads no aux
280s ret: write_header(): 0
280s ret: write_record(): 0
280s ret: write_record(): 0
280s ret: write_record(): 0
280s ret: write_record(): 0
280s ret: write_record(): 0
280s ret: write_record(): 0
280s ret: write_record(): 0
280s ret: write_record(): 0
280s get_all_headers
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation running
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write() ret: 152983
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_free()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: function complete, returning 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation running
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write() ret: 76391
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_free()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: function complete, returning 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation running
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write() ret: 152983
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_free()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: function complete, returning 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation running
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write() ret: 76391
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_free()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: function complete, returning 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation running
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write() ret: 152983
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_free()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: function complete, returning 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation running
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write() ret: 76391
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_free()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: function complete, returning 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation running
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write() ret: 153017
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_free()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: function complete, returning 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation running
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write() ret: 76425
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_free()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: function complete, returning 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: -1
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next reached end of file (EOF)(-1): -1: ['SLOW5_ERR_EOF', 'End Of File reached']
280s 12-Jul-24 22:50:57 - [DEBUG]: examples/example2.slow5 closed
280s 12-Jul-24 22:50:57 - [DEBUG]: examples/example_write_append.blow5 closed
280s 12-Jul-24 22:50:57 - [DEBUG]: FILE: examples/example_write_aux.blow5, mode: w
280s 12-Jul-24 22:50:57 - [DEBUG]: FILE: b'examples/example_write_aux.blow5', mode: b'w'
280s 12-Jul-24 22:50:57 - [DEBUG]: examples/example_write_append.blow5 already closed
280s 12-Jul-24 22:50:57 - [DEBUG]: pathname: examples/example_write_append.blow5
280s 12-Jul-24 22:50:57 - [DEBUG]: total_time_slow5_get_next: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_time_yield_reads: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_single_write_time: 0.028609275817871094 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_multi_write_time: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: FILE: examples/example2.slow5, mode: r
280s 12-Jul-24 22:50:57 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r'
280s 12-Jul-24 22:50:57 - [DEBUG]: Number of read_groups: 4
280s 12-Jul-24 22:50:57 - [DEBUG]: pathname: examples/example2.slow5
280s 12-Jul-24 22:50:57 - [DEBUG]: total_time_slow5_get_next: 0.021792888641357422 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_time_yield_reads: 0.022681713104248047 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_single_write_time: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_multi_write_time: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: get_aux_names starting
280s 12-Jul-24 22:50:57 - [DEBUG]: get_aux_names aux_len: 5
280s 12-Jul-24 22:50:57 - [DEBUG]: get_aux_types starting
280s 12-Jul-24 22:50:57 - [DEBUG]: get_aux_types aux_len: 5
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation running
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checking header stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: writting header...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: header written
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: channel_number: 281
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string running...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string type: <class 'str'>
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: median_before: 231.363533
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: read_number: 4019
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: start_mux: 1
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: start_time: 78470500
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: aux stuff done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write() ret: 67258
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_free()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: function complete, returning 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation running
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: channel_number: 391
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string running...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string type: <class 'str'>
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: median_before: 260.557264
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: read_number: 2287
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: start_mux: 2
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: start_time: 36886851
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: aux stuff done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write() ret: 32408
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_free()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: function complete, returning 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation running
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: channel_number: 281
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string running...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string type: <class 'str'>
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: median_before: 231.363533
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: read_number: 4019
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: start_mux: 1
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: start_time: 78470500
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: aux stuff done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write() ret: 67258
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_free()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: function complete, returning 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation running
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: channel_number: 391
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string running...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string type: <class 'str'>
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: median_before: 260.557264
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: read_number: 2287
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: start_mux: 2
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: start_time: 36886851
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: aux stuff done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write() ret: 32408
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_free()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: function complete, returning 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation running
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: channel_number: 281
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string running...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string type: <class 'str'>
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: median_before: 231.363533
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: read_number: 4019
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: start_mux: 1
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: start_time: 78470500
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: aux stuff done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write() ret: 67260
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_free()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: function complete, returning 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation running
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: channel_number: 391
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string running...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string type: <class 'str'>
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: median_before: 260.557264
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: read_number: 2287
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: start_mux: 2
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: start_time: 36886851
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: aux stuff done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write() ret: 32408
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_free()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: function complete, returning 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation running
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: channel_number: 281
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string running...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string type: <class 'str'>
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: median_before: 231.363533
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: read_number: 4019
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: start_mux: 1
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: start_time: 78470500
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: aux stuff done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write() ret: 67298
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_free()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: function complete, returning 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation running
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: channel_number: 391
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string running...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string type: <class 'str'>
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: median_before: 260.557264
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: read_number: 2287
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: start_mux: 2
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: start_time: 36886851
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: aux stuff done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write() ret: 32446
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_free()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: function complete, returning 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: -1
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next reached end of file (EOF)(-1): -1: ['SLOW5_ERR_EOF', 'End Of File reached']
280s 12-Jul-24 22:50:57 - [DEBUG]: examples/example2.slow5 closed
280s 12-Jul-24 22:50:57 - [DEBUG]: examples/example_write_aux.blow5 closed
280s 12-Jul-24 22:50:57 - [DEBUG]: FILE: examples/example_write_append_aux.blow5, mode: w
280s 12-Jul-24 22:50:57 - [DEBUG]: FILE: b'examples/example_write_append_aux.blow5', mode: b'w'
280s 12-Jul-24 22:50:57 - [DEBUG]: examples/example_write_aux.blow5 already closed
280s 12-Jul-24 22:50:57 - [DEBUG]: pathname: examples/example_write_aux.blow5
280s 12-Jul-24 22:50:57 - [DEBUG]: total_time_slow5_get_next: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_time_yield_reads: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_single_write_time: 0.028630733489990234 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_multi_write_time: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: FILE: examples/example2.slow5, mode: r
280s 12-Jul-24 22:50:57 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r'
280s 12-Jul-24 22:50:57 - [DEBUG]: Number of read_groups: 4
280s 12-Jul-24 22:50:57 - [DEBUG]: pathname: examples/example2.slow5
280s 12-Jul-24 22:50:57 - [DEBUG]: total_time_slow5_get_next: 0.02201676368713379 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_time_yield_reads: 0.02325153350830078 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_single_write_time: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_multi_write_time: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: get_aux_names starting
280s 12-Jul-24 22:50:57 - [DEBUG]: get_aux_names aux_len: 5
280s 12-Jul-24 22:50:57 - [DEBUG]: get_aux_types starting
280s 12-Jul-24 22:50:57 - [DEBUG]: get_aux_types aux_len: 5
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation running
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checking header stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: writting header...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: header written
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: channel_number: 281
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string running...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string type: <class 'str'>
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: median_before: 231.363533
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: read_number: 4019
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: start_mux: 1
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: start_time: 78470500
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: aux stuff done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write() ret: 153008
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_free()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: function complete, returning 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation running
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: channel_number: 391
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string running...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string type: <class 'str'>
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: median_before: 260.557264
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: read_number: 2287
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: start_mux: 2
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: start_time: 36886851
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: aux stuff done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write() ret: 76416
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_free()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: function complete, returning 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation running
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: channel_number: 281
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string running...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string type: <class 'str'>
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: median_before: 231.363533
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: read_number: 4019
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: start_mux: 1
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: start_time: 78470500
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: aux stuff done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write() ret: 153008
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_free()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: function complete, returning 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation running
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: channel_number: 391
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string running...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string type: <class 'str'>
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: median_before: 260.557264
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: read_number: 2287
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: start_mux: 2
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: start_time: 36886851
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: aux stuff done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write() ret: 76416
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_free()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: function complete, returning 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation running
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: channel_number: 281
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string running...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string type: <class 'str'>
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: median_before: 231.363533
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: read_number: 4019
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: start_mux: 1
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: start_time: 78470500
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: aux stuff done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write() ret: 153008
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_free()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: function complete, returning 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation running
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: channel_number: 391
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string running...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string type: <class 'str'>
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: median_before: 260.557264
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: read_number: 2287
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: start_mux: 2
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: start_time: 36886851
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: aux stuff done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write() ret: 76416
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_free()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: function complete, returning 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation running
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: channel_number: 281
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string running...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string type: <class 'str'>
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: median_before: 231.363533
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: read_number: 4019
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: start_mux: 1
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: start_time: 78470500
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: aux stuff done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write() ret: 153042
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_free()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: function complete, returning 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation running
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: channel_number: 391
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string running...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string type: <class 'str'>
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: median_before: 260.557264
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: read_number: 2287
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: start_mux: 2
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: start_time: 36886851
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: aux stuff done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write() ret: 76450
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_free()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: function complete, returning 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: -1
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next reached end of file (EOF)(-1): -1: ['SLOW5_ERR_EOF', 'End Of File reached']
280s 12-Jul-24 22:50:57 - [DEBUG]: examples/example2.slow5 closed
280s 12-Jul-24 22:50:57 - [DEBUG]: examples/example_write_append_aux.blow5 closed
280s 12-Jul-24 22:50:57 - [DEBUG]: FILE: examples/example_write_append_aux.blow5, mode: a
280s 12-Jul-24 22:50:57 - [DEBUG]: FILE: b'examples/example_write_append_aux.blow5', mode: b'a'
280s 12-Jul-24 22:50:57 - [DEBUG]: examples/example_write_append.blow5 already closed
280s 12-Jul-24 22:50:57 - [DEBUG]: pathname: examples/example_write_append.blow5
280s 12-Jul-24 22:50:57 - [DEBUG]: total_time_slow5_get_next: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_time_yield_reads: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_single_write_time: 0.028675317764282227 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_multi_write_time: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: FILE: examples/example2.slow5, mode: r
280s 12-Jul-24 22:50:57 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r'
280s 12-Jul-24 22:50:57 - [DEBUG]: Number of read_groups: 4
280s 12-Jul-24 22:50:57 - [DEBUG]: pathname: examples/example2.slow5
280s 12-Jul-24 22:50:57 - [DEBUG]: total_time_slow5_get_next: 0.021993160247802734 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_time_yield_reads: 0.02311992645263672 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_single_write_time: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_multi_write_time: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: get_aux_names starting
280s 12-Jul-24 22:50:57 - [DEBUG]: get_aux_names aux_len: 5
280s 12-Jul-24 22:50:57 - [DEBUG]: get_aux_types starting
280s 12-Jul-24 22:50:57 - [DEBUG]: get_aux_types aux_len: 5
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation running
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: channel_number: 281
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string running...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string type: <class 'str'>
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: median_before: 231.363533
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: read_number: 4019
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: start_mux: 1
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: start_time: 78470500
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: aux stuff done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write() ret: 153015
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_free()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: function complete, returning 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation running
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: channel_number: 391
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string running...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string type: <class 'str'>
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: median_before: 260.557264
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: read_number: 2287
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: start_mux: 2
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: start_time: 36886851
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: aux stuff done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write() ret: 76423
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_free()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: function complete, returning 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation running
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: channel_number: 281
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string running...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string type: <class 'str'>
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: median_before: 231.363533
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: read_number: 4019
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: start_mux: 1
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: start_time: 78470500
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: aux stuff done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write() ret: 153015
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_free()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: function complete, returning 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation running
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: channel_number: 391
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string running...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string type: <class 'str'>
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: median_before: 260.557264
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: read_number: 2287
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: start_mux: 2
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: start_time: 36886851
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: aux stuff done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write() ret: 76423
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_free()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: function complete, returning 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation running
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: channel_number: 281
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string running...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string type: <class 'str'>
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: median_before: 231.363533
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: read_number: 4019
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: start_mux: 1
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: start_time: 78470500
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: aux stuff done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write() ret: 153015
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_free()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: function complete, returning 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation running
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: channel_number: 391
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string running...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string type: <class 'str'>
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: median_before: 260.557264
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: read_number: 2287
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: start_mux: 2
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: start_time: 36886851
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: aux stuff done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write() ret: 76423
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_free()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: function complete, returning 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation running
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: channel_number: 281
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string running...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string type: <class 'str'>
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: median_before: 231.363533
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: read_number: 4019
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: start_mux: 1
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: start_time: 78470500
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: aux stuff done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write() ret: 153049
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_free()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: function complete, returning 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation running
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: _record_type_validation done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: channel_number: 391
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string running...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string type: <class 'str'>
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: median_before: 260.557264
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: read_number: 2287
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: start_mux: 2
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: checked_aux: start_time: 36886851
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: aux stuff done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_write() ret: 76457
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: slow5_rec_free()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record: function complete, returning 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: -1
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next reached end of file (EOF)(-1): -1: ['SLOW5_ERR_EOF', 'End Of File reached']
280s 12-Jul-24 22:50:57 - [DEBUG]: examples/example2.slow5 closed
280s 12-Jul-24 22:50:57 - [DEBUG]: examples/example_write_append_aux.blow5 closed
280s 12-Jul-24 22:50:57 - [DEBUG]: FILE: examples/example2.slow5, mode: r
280s 12-Jul-24 22:50:57 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r'
280s 12-Jul-24 22:50:57 - [DEBUG]: Number of read_groups: 4
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next_multi return: 3
280s 12-Jul-24 22:50:57 - [DEBUG]: get_aux_names starting
280s 12-Jul-24 22:50:57 - [DEBUG]: get_aux_names aux_len: 5
280s 12-Jul-24 22:50:57 - [DEBUG]: get_aux_types starting
280s 12-Jul-24 22:50:57 - [DEBUG]: get_aux_types aux_len: 5
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next_multi return: 3
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next_multi return: 2
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next_multi has no more batches - batchsize:3 ret:2
280s 12-Jul-24 22:50:57 - [DEBUG]: seq_reads_multi timings:
280s 12-Jul-24 22:50:57 - [DEBUG]: aux_total_time: 0.00026726722717285156
280s 12-Jul-24 22:50:57 - [DEBUG]: primary_total_time: 0.0002865791320800781
280s 12-Jul-24 22:50:57 - [DEBUG]: pA_total_time: 0.004389286041259766
280s 12-Jul-24 22:50:57 - [DEBUG]: signal_total_time: 0.0002548694610595703
280s 12-Jul-24 22:50:57 - [DEBUG]: examples/example2.slow5 closed
280s 12-Jul-24 22:50:57 - [DEBUG]: FILE: examples/example2.slow5, mode: r
280s 12-Jul-24 22:50:57 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r'
280s 12-Jul-24 22:50:57 - [DEBUG]: Number of read_groups: 4
280s 12-Jul-24 22:50:57 - [DEBUG]: pathname: examples/example2.slow5
280s 12-Jul-24 22:50:57 - [DEBUG]: total_time_slow5_get_next: 0.01831197738647461 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_time_yield_reads: 0.00500178337097168 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_single_write_time: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_multi_write_time: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: FILE: examples/example2.slow5, mode: r
280s 12-Jul-24 22:50:57 - [DEBUG]: Creating/loading index...
280s 12-Jul-24 22:50:57 - [DEBUG]: Setting up batching...
280s 12-Jul-24 22:50:57 - [DEBUG]: read_list: ['r0', 'r1', 'r2', 'r3', 'r4', 'r5', '0a238451-b9ed-446d-a152-badd074006c4', '0d624d4b-671f-40b8-9798-84f2ccc4d7fc']
280s 12-Jul-24 22:50:57 - [DEBUG]: batch for loop start
280s 12-Jul-24 22:50:57 - [DEBUG]: Batch: r0,r1,r2
280s 12-Jul-24 22:50:57 - [DEBUG]: Starting rid assignment
280s 12-Jul-24 22:50:57 - [DEBUG]: readID: r0, bin: b'r0'
280s 12-Jul-24 22:50:57 - [DEBUG]: readID: r1, bin: b'r1'
280s 12-Jul-24 22:50:57 - [DEBUG]: readID: r2, bin: b'r2'
280s 12-Jul-24 22:50:57 - [DEBUG]: rid assignment complete
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_batch: num_reads: 3
280s 12-Jul-24 22:50:57 - [DEBUG]: get_read_multi slow5_get_batch ret: 3
280s 12-Jul-24 22:50:57 - [DEBUG]: get_aux_names starting
280s 12-Jul-24 22:50:57 - [DEBUG]: get_aux_names aux_len: 5
280s 12-Jul-24 22:50:57 - [DEBUG]: get_aux_types starting
280s 12-Jul-24 22:50:57 - [DEBUG]: get_aux_types aux_len: 5
280s 12-Jul-24 22:50:57 - [DEBUG]: Batch: r3,r4,r5
280s 12-Jul-24 22:50:57 - [DEBUG]: Starting rid assignment
280s 12-Jul-24 22:50:57 - [DEBUG]: readID: r3, bin: b'r3'
280s 12-Jul-24 22:50:57 - [DEBUG]: readID: r4, bin: b'r4'
280s 12-Jul-24 22:50:57 - [DEBUG]: readID: r5, bin: b'r5'
280s 12-Jul-24 22:50:57 - [DEBUG]: rid assignment complete
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_batch: num_reads: 3
280s 12-Jul-24 22:50:57 - [DEBUG]: get_read_multi slow5_get_batch ret: 3
280s 12-Jul-24 22:50:57 - [DEBUG]: Batch: 0a238451-b9ed-446d-a152-badd074006c4,0d624d4b-671f-40b8-9798-84f2ccc4d7fc
280s 12-Jul-24 22:50:57 - [DEBUG]: Starting rid assignment
280s 12-Jul-24 22:50:57 - [DEBUG]: readID: 0a238451-b9ed-446d-a152-badd074006c4, bin: b'0a238451-b9ed-446d-a152-badd074006c4'
280s 12-Jul-24 22:50:57 - [DEBUG]: readID: 0d624d4b-671f-40b8-9798-84f2ccc4d7fc, bin: b'0d624d4b-671f-40b8-9798-84f2ccc4d7fc'
280s 12-Jul-24 22:50:57 - [DEBUG]: rid assignment complete
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_batch: num_reads: 2
280s 12-Jul-24 22:50:57 - [DEBUG]: get_read_multi slow5_get_batch ret: 2
280s 12-Jul-24 22:50:57 - [DEBUG]: seq_reads_multi timings:
280s 12-Jul-24 22:50:57 - [DEBUG]: examples/example2.slow5 closed
280s 12-Jul-24 22:50:57 - [DEBUG]: FILE: examples/example_write_aux_multi.slow5, mode: w
280s 12-Jul-24 22:50:57 - [DEBUG]: FILE: b'examples/example_write_aux_multi.slow5', mode: b'w'
280s 12-Jul-24 22:50:57 - [DEBUG]: Not writing blow5, skipping compression steps
280s 12-Jul-24 22:50:57 - [DEBUG]: examples/example_write_append_aux.blow5 already closed
280s 12-Jul-24 22:50:57 - [DEBUG]: pathname: examples/example_write_append_aux.blow5
280s 12-Jul-24 22:50:57 - [DEBUG]: total_time_slow5_get_next: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_time_yield_reads: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_single_write_time: 0.02860093116760254 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_multi_write_time: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: FILE: examples/example2.slow5, mode: r
280s 12-Jul-24 22:50:57 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r'
280s 12-Jul-24 22:50:57 - [DEBUG]: Number of read_groups: 4
280s 12-Jul-24 22:50:57 - [DEBUG]: pathname: examples/example2.slow5
280s 12-Jul-24 22:50:57 - [DEBUG]: total_time_slow5_get_next: 0.02198052406311035 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_time_yield_reads: 0.02310347557067871 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_single_write_time: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_multi_write_time: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: get_aux_names starting
280s 12-Jul-24 22:50:57 - [DEBUG]: get_aux_names aux_len: 5
280s 12-Jul-24 22:50:57 - [DEBUG]: get_aux_types starting
280s 12-Jul-24 22:50:57 - [DEBUG]: get_aux_types aux_len: 5
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: 0
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next return: -1
280s 12-Jul-24 22:50:57 - [DEBUG]: slow5_get_next reached end of file (EOF)(-1): -1: ['SLOW5_ERR_EOF', 'End Of File reached']
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: Setting up batching...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: batch for loop start
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: _record_type_validation running
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux stuff done
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux stuff done
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux stuff done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: _record_type_validation done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: checking header stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: writting header...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: header written
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: checked_aux: channel_number: 281
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: slow5_aux_set_string running...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: slow5_aux_set_string type: <class 'str'>
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: slow5_aux_set_string running done: ret = 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: checked_aux: median_before: 231.363533
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: checked_aux: read_number: 4019
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: checked_aux: start_mux: 1
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: checked_aux: start_time: 78470500
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: aux stuff done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: checked_aux: channel_number: 391
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: slow5_aux_set_string running...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: slow5_aux_set_string type: <class 'str'>
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: slow5_aux_set_string running done: ret = 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: checked_aux: median_before: 260.557264
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: checked_aux: read_number: 2287
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: checked_aux: start_mux: 2
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: checked_aux: start_time: 36886851
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: aux stuff done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: checked_aux: channel_number: 281
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: slow5_aux_set_string running...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: slow5_aux_set_string type: <class 'str'>
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: slow5_aux_set_string running done: ret = 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: checked_aux: median_before: 231.363533
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: checked_aux: read_number: 4019
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: checked_aux: start_mux: 1
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: checked_aux: start_time: 78470500
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: aux stuff done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: slow5_write_batch()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: free()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: free() aux
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: _record_type_validation running
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux stuff done
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux stuff done
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux stuff done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: _record_type_validation done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: checked_aux: channel_number: 391
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: slow5_aux_set_string running...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: slow5_aux_set_string type: <class 'str'>
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: slow5_aux_set_string running done: ret = 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: checked_aux: median_before: 260.557264
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: checked_aux: read_number: 2287
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: checked_aux: start_mux: 2
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: checked_aux: start_time: 36886851
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: aux stuff done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: checked_aux: channel_number: 281
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: slow5_aux_set_string running...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: slow5_aux_set_string type: <class 'str'>
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: slow5_aux_set_string running done: ret = 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: checked_aux: median_before: 231.363533
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: checked_aux: read_number: 4019
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: checked_aux: start_mux: 1
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: checked_aux: start_time: 78470500
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: aux stuff done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: checked_aux: channel_number: 391
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: slow5_aux_set_string running...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: slow5_aux_set_string type: <class 'str'>
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: slow5_aux_set_string running done: ret = 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: checked_aux: median_before: 260.557264
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: checked_aux: read_number: 2287
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: checked_aux: start_mux: 2
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: checked_aux: start_time: 36886851
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: aux stuff done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: slow5_write_batch()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: free()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: free() aux
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: _record_type_validation running
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux stuff done
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: doing aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux passed tests...
280s 12-Jul-24 22:50:57 - [DEBUG]: _record_type_validation: aux stuff done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: _record_type_validation done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: checked_aux: channel_number: 281
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: slow5_aux_set_string running...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: slow5_aux_set_string type: <class 'str'>
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: slow5_aux_set_string running done: ret = 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: checked_aux: median_before: 231.363533
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: checked_aux: read_number: 4019
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: checked_aux: start_mux: 1
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: checked_aux: start_time: 78470500
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: aux stuff done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: slow5_rec_init()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: self.write assignments...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: self.write.raw_signal malloc...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: self.write.raw_signal malloc done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: self.write assignments done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: self.write processing raw_signal
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: self.write raw_signal done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: aux stuff...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: checked_aux: channel_number: 391
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: slow5_aux_set_string running...
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: slow5_aux_set_string type: <class 'str'>
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: slow5_aux_set_string running done: ret = 0
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: checked_aux: median_before: 260.557264
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: checked_aux: read_number: 2287
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: checked_aux: start_mux: 2
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: checked_aux: start_time: 36886851
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: aux stuff done
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: slow5_write_batch()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: free()
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: free() aux
280s 12-Jul-24 22:50:57 - [DEBUG]: write_record_batch: function complete, returning 0
280s 12-Jul-24 22:50:57 - [DEBUG]: examples/example2.slow5 closed
280s 12-Jul-24 22:50:57 - [DEBUG]: examples/example_write_aux_multi.slow5 closed
280s 12-Jul-24 22:50:57 - [DEBUG]: FILE: examples/example2.slow5, mode: r
280s 12-Jul-24 22:50:57 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r'
280s 12-Jul-24 22:50:57 - [DEBUG]: Number of read_groups: 4
280s 12-Jul-24 22:50:57 - [DEBUG]: pathname: examples/example2.slow5
280s {'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'}
280s ret: write_record(): 0
280s ret: write_record(): 0
280s ret: write_record(): 0
280s ret: write_record(): 0
280s ret: write_record(): 0
280s ret: write_record(): 0
280s ret: write_record(): 0
280s ret: write_record(): 0
280s ==============================================
280s write reads with aux
280s ret: write_header(): 0
280s ret: write_header(): 0
280s ret: write_record(): 0
280s ret: write_record(): 0
280s ret: write_record(): 0
280s ret: write_record(): 0
280s ret: write_record(): 0
280s ret: write_record(): 0
280s ret: write_record(): 0
280s ret: write_record(): 0
280s ==============================================
280s append reads with aux
280s ret: write_header(): 0
280s ret: write_header(): 0
280s ret: write_record(): 0
280s ret: write_record(): 0
280s ret: write_record(): 0
280s ret: write_record(): 0
280s ret: write_record(): 0
280s ret: write_record(): 0
280s ret: write_record(): 0
280s ret: write_record(): 0
280s ret: write_record(): 0
280s ret: write_record(): 0
280s ret: write_record(): 0
280s ret: write_record(): 0
280s ret: write_record(): 0
280s ret: write_record(): 0
280s ret: write_record(): 0
280s ret: write_record(): 0
280s ==============================================
280s seq_reads_multi with aux:
280s type check reads: <class '_cython_3_0_8.generator'>
280s r0
280s read_number 4019
280s r1
280s read_number 2287
280s r2
280s read_number 4019
280s r3
280s read_number 2287
280s r4
280s read_number 4019
280s r5
280s read_number 2287
280s 0a238451-b9ed-446d-a152-badd074006c4
280s read_number 4019
280s 0d624d4b-671f-40b8-9798-84f2ccc4d7fc
280s read_number 2287
280s ==============================================
280s get_reads_multi with aux:
280s type check reads: <class '_cython_3_0_8.generator'>
280s r0
280s read_number 4019
280s r1
280s read_number 2287
280s r2
280s read_number 4019
280s r3
280s read_number 2287
280s r4
280s read_number 4019
280s r5
280s read_number 2287
280s 0a238451-b9ed-446d-a152-badd074006c4
280s read_number 4019
280s 0d624d4b-671f-40b8-9798-84f2ccc4d7fc
280s read_number 2287
280s ==============================================
280s write reads with aux multi
280s ret: write_header(): 0
280s ret: write_header(): 0
280s {'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)}}
280s {'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}}
280s ret: write_record(): 0
280s ==============================================
280s get all readIDs from index
280s ['r0', 'r1', 'r2', 'r3', 'r4', 'r5', '0a238451-b9ed-446d-a152-badd074006c4', '0d624d4b-671f-40b8-9798-84f2ccc4d7fc']
280s number of reads: 8
280s ==============================================
280s done
280s 12-Jul-24 22:50:57 - [DEBUG]: total_time_slow5_get_next: 0.022268295288085938 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_time_yield_reads: 0.023460865020751953 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_single_write_time: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_multi_write_time: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: FILE: examples/example2.slow5, mode: r
280s 12-Jul-24 22:50:57 - [DEBUG]: Creating/loading index...
280s 12-Jul-24 22:50:57 - [DEBUG]: examples/example2.slow5 closed
280s 12-Jul-24 22:50:57 - [DEBUG]: pathname: examples/example.slow5
280s 12-Jul-24 22:50:57 - [DEBUG]: total_time_slow5_get_next: 0.014370441436767578 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_time_yield_reads: 0.0149993896484375 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_single_write_time: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_multi_write_time: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: pathname: examples/example2.slow5
280s 12-Jul-24 22:50:57 - [DEBUG]: total_time_slow5_get_next: 0.02223062515258789 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_time_yield_reads: 0.02854323387145996 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_single_write_time: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_multi_write_time: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: examples/example_write_aux_multi.slow5 already closed
280s 12-Jul-24 22:50:57 - [DEBUG]: pathname: examples/example_write_aux_multi.slow5
280s 12-Jul-24 22:50:57 - [DEBUG]: total_time_slow5_get_next: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_time_yield_reads: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_single_write_time: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_multi_write_signal_time: 0.03068399429321289 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_multi_write_time: 0.06252479553222656 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: pathname: examples/example2.slow5
280s 12-Jul-24 22:50:57 - [DEBUG]: total_time_slow5_get_next: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_time_yield_reads: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_single_write_time: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_multi_write_time: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: examples/example_write_append_aux.blow5 already closed
280s 12-Jul-24 22:50:57 - [DEBUG]: pathname: examples/example_write_append_aux.blow5
280s 12-Jul-24 22:50:57 - [DEBUG]: total_time_slow5_get_next: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_time_yield_reads: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_single_write_time: 0.02863931655883789 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_multi_write_time: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: pathname: examples/example2.slow5
280s 12-Jul-24 22:50:57 - [DEBUG]: total_time_slow5_get_next: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_time_yield_reads: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_single_write_time: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds
280s 12-Jul-24 22:50:57 - [DEBUG]: total_multi_write_time: 0.0 seconds
280s autopkgtest [22:50:57]: test run-pybinding-test: -----------------------]
285s autopkgtest [22:51:02]: test run-pybinding-test:  - - - - - - - - - - results - - - - - - - - - -
285s run-pybinding-test   PASS
289s autopkgtest [22:51:06]: test run-pkg-test: preparing testbed
344s autopkgtest [22:52:01]: testbed dpkg architecture: armhf
346s autopkgtest [22:52:03]: testbed apt version: 2.9.6
346s autopkgtest [22:52:03]: @@@@@@@@@@@@@@@@@@@@ test bed setup
354s Get:1 http://ftpmaster.internal/ubuntu oracular-proposed InRelease [126 kB]
354s Get:2 http://ftpmaster.internal/ubuntu oracular-proposed/main Sources [46.5 kB]
354s Get:3 http://ftpmaster.internal/ubuntu oracular-proposed/restricted Sources [8548 B]
354s Get:4 http://ftpmaster.internal/ubuntu oracular-proposed/universe Sources [360 kB]
354s Get:5 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse Sources [3288 B]
354s Get:6 http://ftpmaster.internal/ubuntu oracular-proposed/main armhf Packages [57.9 kB]
354s Get:7 http://ftpmaster.internal/ubuntu oracular-proposed/main armhf c-n-f Metadata [1440 B]
354s Get:8 http://ftpmaster.internal/ubuntu oracular-proposed/restricted armhf Packages [1368 B]
354s Get:9 http://ftpmaster.internal/ubuntu oracular-proposed/restricted armhf c-n-f Metadata [120 B]
354s Get:10 http://ftpmaster.internal/ubuntu oracular-proposed/universe armhf Packages [309 kB]
354s Get:11 http://ftpmaster.internal/ubuntu oracular-proposed/universe armhf c-n-f Metadata [6960 B]
354s Get:12 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse armhf Packages [1796 B]
354s Get:13 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse armhf c-n-f Metadata [120 B]
356s Fetched 922 kB in 1s (1051 kB/s)
356s Reading package lists...
371s tee: /proc/self/fd/2: Permission denied
394s Hit:1 http://ftpmaster.internal/ubuntu oracular-proposed InRelease
394s Hit:2 http://ftpmaster.internal/ubuntu oracular InRelease
394s Hit:3 http://ftpmaster.internal/ubuntu oracular-updates InRelease
394s Hit:4 http://ftpmaster.internal/ubuntu oracular-security InRelease
395s Reading package lists...
395s Reading package lists...
395s Building dependency tree...
395s Reading state information...
396s Calculating upgrade...
396s The following packages will be upgraded:
396s   inetutils-telnet libc-bin libc6 libssl3t64 locales openssh-client
396s   openssh-server openssh-sftp-server openssl telnet
396s 10 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.
396s Need to get 11.9 MB of archives.
396s After this operation, 285 kB of additional disk space will be used.
396s Get:1 http://ftpmaster.internal/ubuntu oracular-proposed/main armhf libc6 armhf 2.39-3.1ubuntu3 [2825 kB]
397s Get:2 http://ftpmaster.internal/ubuntu oracular-proposed/main armhf libc-bin armhf 2.39-3.1ubuntu3 [527 kB]
397s Get:3 http://ftpmaster.internal/ubuntu oracular/main armhf libssl3t64 armhf 3.2.2-1ubuntu1 [1729 kB]
397s Get:4 http://ftpmaster.internal/ubuntu oracular/main armhf openssh-sftp-server armhf 1:9.6p1-3ubuntu17 [35.6 kB]
397s Get:5 http://ftpmaster.internal/ubuntu oracular/main armhf openssh-server armhf 1:9.6p1-3ubuntu17 [502 kB]
397s Get:6 http://ftpmaster.internal/ubuntu oracular/main armhf openssh-client armhf 1:9.6p1-3ubuntu17 [888 kB]
397s Get:7 http://ftpmaster.internal/ubuntu oracular-proposed/main armhf locales all 2.39-3.1ubuntu3 [4220 kB]
397s Get:8 http://ftpmaster.internal/ubuntu oracular/main armhf openssl armhf 3.2.2-1ubuntu1 [1095 kB]
397s Get:9 http://ftpmaster.internal/ubuntu oracular/main armhf inetutils-telnet armhf 2:2.5-5ubuntu1 [94.4 kB]
397s Get:10 http://ftpmaster.internal/ubuntu oracular/main armhf telnet all 0.17+2.5-5ubuntu1 [3688 B]
398s Preconfiguring packages ...
398s Fetched 11.9 MB in 1s (13.0 MB/s)
398s (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 ... 58437 files and directories currently installed.)
398s Preparing to unpack .../libc6_2.39-3.1ubuntu3_armhf.deb ...
398s Unpacking libc6:armhf (2.39-3.1ubuntu3) over (2.39-0ubuntu9) ...
398s Setting up libc6:armhf (2.39-3.1ubuntu3) ...
398s Error: Could not restart systemd, systemd binary not working
398s (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 ... 58437 files and directories currently installed.)
398s Preparing to unpack .../libc-bin_2.39-3.1ubuntu3_armhf.deb ...
398s Unpacking libc-bin (2.39-3.1ubuntu3) over (2.39-0ubuntu9) ...
398s Setting up libc-bin (2.39-3.1ubuntu3) ...
399s (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 ... 58437 files and directories currently installed.)
399s Preparing to unpack .../libssl3t64_3.2.2-1ubuntu1_armhf.deb ...
399s Unpacking libssl3t64:armhf (3.2.2-1ubuntu1) over (3.2.1-3ubuntu1) ...
399s Setting up libssl3t64:armhf (3.2.2-1ubuntu1) ...
399s (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 ... 58437 files and directories currently installed.)
399s Preparing to unpack .../0-openssh-sftp-server_1%3a9.6p1-3ubuntu17_armhf.deb ...
399s Unpacking openssh-sftp-server (1:9.6p1-3ubuntu17) over (1:9.6p1-3ubuntu15) ...
399s Preparing to unpack .../1-openssh-server_1%3a9.6p1-3ubuntu17_armhf.deb ...
399s Unpacking openssh-server (1:9.6p1-3ubuntu17) over (1:9.6p1-3ubuntu15) ...
399s Preparing to unpack .../2-openssh-client_1%3a9.6p1-3ubuntu17_armhf.deb ...
399s Unpacking openssh-client (1:9.6p1-3ubuntu17) over (1:9.6p1-3ubuntu15) ...
399s Preparing to unpack .../3-locales_2.39-3.1ubuntu3_all.deb ...
399s Unpacking locales (2.39-3.1ubuntu3) over (2.39-0ubuntu9) ...
399s Preparing to unpack .../4-openssl_3.2.2-1ubuntu1_armhf.deb ...
399s Unpacking openssl (3.2.2-1ubuntu1) over (3.2.1-3ubuntu1) ...
399s Preparing to unpack .../5-inetutils-telnet_2%3a2.5-5ubuntu1_armhf.deb ...
400s Unpacking inetutils-telnet (2:2.5-5ubuntu1) over (2:2.5-3ubuntu4) ...
400s Preparing to unpack .../6-telnet_0.17+2.5-5ubuntu1_all.deb ...
400s Unpacking telnet (0.17+2.5-5ubuntu1) over (0.17+2.5-3ubuntu4) ...
400s Setting up openssh-client (1:9.6p1-3ubuntu17) ...
400s Setting up inetutils-telnet (2:2.5-5ubuntu1) ...
400s Setting up locales (2.39-3.1ubuntu3) ...
400s Generating locales (this might take a while)...
402s   en_US.UTF-8... done
402s Generation complete.
402s Setting up openssl (3.2.2-1ubuntu1) ...
402s Installing new version of config file /etc/ssl/openssl.cnf ...
402s Setting up openssh-sftp-server (1:9.6p1-3ubuntu17) ...
402s Setting up telnet (0.17+2.5-5ubuntu1) ...
402s Setting up openssh-server (1:9.6p1-3ubuntu17) ...
402s Installing new version of config file /etc/pam.d/sshd ...
404s Processing triggers for ufw (0.36.2-6) ...
404s Processing triggers for systemd (256-1ubuntu1) ...
404s Processing triggers for man-db (2.12.1-2) ...
405s Processing triggers for libc-bin (2.39-3.1ubuntu3) ...
405s Reading package lists...
406s Building dependency tree...
406s Reading state information...
406s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.
408s autopkgtest [22:53:05]: rebooting testbed after setup commands that affected boot
512s Reading package lists...
512s Building dependency tree...
512s Reading state information...
512s Starting pkgProblemResolver with broken count: 0
513s Starting 2 pkgProblemResolver with broken count: 0
513s Done
513s The following additional packages will be installed:
513s   build-essential cpp cpp-13 cpp-13-arm-linux-gnueabihf
513s   cpp-arm-linux-gnueabihf g++ g++-13 g++-13-arm-linux-gnueabihf
513s   g++-arm-linux-gnueabihf gcc gcc-13 gcc-13-arm-linux-gnueabihf gcc-13-base
513s   gcc-arm-linux-gnueabihf libasan8 libatomic1 libblas3 libc-dev-bin libc6-dev
513s   libcc1-0 libcrypt-dev libgcc-13-dev libgfortran5 libgomp1 libisl23
513s   liblapack3 libmpc3 libslow5-0t64 libslow5-dev libstdc++-13-dev
513s   libstreamvbyte-dev libstreamvbyte0 libubsan1 linux-libc-dev python3-numpy
513s   python3-slow5 rpcsvc-proto zlib1g-dev
513s Suggested packages:
513s   cpp-doc gcc-13-locales cpp-13-doc gcc-13-doc gcc-multilib manpages-dev
513s   autoconf automake libtool flex bison gdb gcc-doc gdb-arm-linux-gnueabihf
513s   libc-devtools glibc-doc libstdc++-13-doc gfortran python-numpy-doc
513s   python3-dev python3-pytest
513s Recommended packages:
513s   manpages manpages-dev
513s The following NEW packages will be installed:
513s   autopkgtest-satdep build-essential cpp cpp-13 cpp-13-arm-linux-gnueabihf
513s   cpp-arm-linux-gnueabihf g++ g++-13 g++-13-arm-linux-gnueabihf
513s   g++-arm-linux-gnueabihf gcc gcc-13 gcc-13-arm-linux-gnueabihf gcc-13-base
513s   gcc-arm-linux-gnueabihf libasan8 libatomic1 libblas3 libc-dev-bin libc6-dev
513s   libcc1-0 libcrypt-dev libgcc-13-dev libgfortran5 libgomp1 libisl23
513s   liblapack3 libmpc3 libslow5-0t64 libslow5-dev libstdc++-13-dev
513s   libstreamvbyte-dev libstreamvbyte0 libubsan1 linux-libc-dev python3-numpy
513s   python3-slow5 rpcsvc-proto zlib1g-dev
513s 0 upgraded, 39 newly installed, 0 to remove and 0 not upgraded.
513s Need to get 55.0 MB/55.0 MB of archives.
513s After this operation, 171 MB of additional disk space will be used.
513s Get:1 /tmp/autopkgtest.HDZm8r/2-autopkgtest-satdep.deb autopkgtest-satdep armhf 0 [756 B]
513s Get:2 http://ftpmaster.internal/ubuntu oracular-proposed/main armhf libc-dev-bin armhf 2.39-3.1ubuntu3 [19.1 kB]
514s Get:3 http://ftpmaster.internal/ubuntu oracular/main armhf linux-libc-dev armhf 6.8.0-31.31 [1557 kB]
514s Get:4 http://ftpmaster.internal/ubuntu oracular/main armhf libcrypt-dev armhf 1:4.4.36-4build1 [120 kB]
514s Get:5 http://ftpmaster.internal/ubuntu oracular/main armhf rpcsvc-proto armhf 1.4.2-0ubuntu7 [62.2 kB]
514s Get:6 http://ftpmaster.internal/ubuntu oracular-proposed/main armhf libc6-dev armhf 2.39-3.1ubuntu3 [1350 kB]
514s Get:7 http://ftpmaster.internal/ubuntu oracular/main armhf gcc-13-base armhf 13.2.0-23ubuntu4 [48.9 kB]
514s Get:8 http://ftpmaster.internal/ubuntu oracular/main armhf libisl23 armhf 0.26-3build1 [544 kB]
514s Get:9 http://ftpmaster.internal/ubuntu oracular/main armhf libmpc3 armhf 1.3.1-1build1 [46.7 kB]
514s Get:10 http://ftpmaster.internal/ubuntu oracular/main armhf cpp-13-arm-linux-gnueabihf armhf 13.2.0-23ubuntu4 [8759 kB]
514s Get:11 http://ftpmaster.internal/ubuntu oracular/main armhf cpp-13 armhf 13.2.0-23ubuntu4 [1034 B]
514s Get:12 http://ftpmaster.internal/ubuntu oracular/main armhf cpp-arm-linux-gnueabihf armhf 4:13.2.0-7ubuntu1 [5320 B]
514s Get:13 http://ftpmaster.internal/ubuntu oracular/main armhf cpp armhf 4:13.2.0-7ubuntu1 [22.4 kB]
514s Get:14 http://ftpmaster.internal/ubuntu oracular/main armhf libcc1-0 armhf 14.1.0-1ubuntu1 [43.3 kB]
514s Get:15 http://ftpmaster.internal/ubuntu oracular/main armhf libgomp1 armhf 14.1.0-1ubuntu1 [125 kB]
514s Get:16 http://ftpmaster.internal/ubuntu oracular/main armhf libatomic1 armhf 14.1.0-1ubuntu1 [7816 B]
514s Get:17 http://ftpmaster.internal/ubuntu oracular/main armhf libasan8 armhf 14.1.0-1ubuntu1 [2913 kB]
514s Get:18 http://ftpmaster.internal/ubuntu oracular/main armhf libubsan1 armhf 14.1.0-1ubuntu1 [1154 kB]
514s Get:19 http://ftpmaster.internal/ubuntu oracular/main armhf libgcc-13-dev armhf 13.2.0-23ubuntu4 [899 kB]
515s Get:20 http://ftpmaster.internal/ubuntu oracular/main armhf gcc-13-arm-linux-gnueabihf armhf 13.2.0-23ubuntu4 [16.9 MB]
516s Get:21 http://ftpmaster.internal/ubuntu oracular/main armhf gcc-13 armhf 13.2.0-23ubuntu4 [453 kB]
516s Get:22 http://ftpmaster.internal/ubuntu oracular/main armhf gcc-arm-linux-gnueabihf armhf 4:13.2.0-7ubuntu1 [1220 B]
516s Get:23 http://ftpmaster.internal/ubuntu oracular/main armhf gcc armhf 4:13.2.0-7ubuntu1 [5022 B]
516s Get:24 http://ftpmaster.internal/ubuntu oracular/main armhf libstdc++-13-dev armhf 13.2.0-23ubuntu4 [2456 kB]
516s Get:25 http://ftpmaster.internal/ubuntu oracular/main armhf g++-13-arm-linux-gnueabihf armhf 13.2.0-23ubuntu4 [9941 kB]
516s Get:26 http://ftpmaster.internal/ubuntu oracular/main armhf g++-13 armhf 13.2.0-23ubuntu4 [14.5 kB]
516s Get:27 http://ftpmaster.internal/ubuntu oracular/main armhf g++-arm-linux-gnueabihf armhf 4:13.2.0-7ubuntu1 [966 B]
516s Get:28 http://ftpmaster.internal/ubuntu oracular/main armhf g++ armhf 4:13.2.0-7ubuntu1 [1090 B]
516s Get:29 http://ftpmaster.internal/ubuntu oracular/main armhf build-essential armhf 12.10ubuntu1 [4928 B]
516s Get:30 http://ftpmaster.internal/ubuntu oracular/main armhf libblas3 armhf 3.12.0-3build1 [123 kB]
516s Get:31 http://ftpmaster.internal/ubuntu oracular/main armhf libgfortran5 armhf 14.1.0-1ubuntu1 [311 kB]
516s Get:32 http://ftpmaster.internal/ubuntu oracular/main armhf liblapack3 armhf 3.12.0-3build1 [2085 kB]
516s Get:33 http://ftpmaster.internal/ubuntu oracular/universe armhf libslow5-0t64 armhf 0.7.0+dfsg-2.1build1 [63.0 kB]
516s Get:34 http://ftpmaster.internal/ubuntu oracular/universe armhf libslow5-dev armhf 0.7.0+dfsg-2.1build1 [84.4 kB]
516s Get:35 http://ftpmaster.internal/ubuntu oracular/universe armhf libstreamvbyte0 armhf 0.4.1-4ubuntu1 [5742 B]
516s Get:36 http://ftpmaster.internal/ubuntu oracular/universe armhf libstreamvbyte-dev armhf 0.4.1-4ubuntu1 [6178 B]
516s Get:37 http://ftpmaster.internal/ubuntu oracular/main armhf python3-numpy armhf 1:1.26.4+ds-10 [3541 kB]
516s Get:38 http://ftpmaster.internal/ubuntu oracular/universe armhf python3-slow5 armhf 0.7.0+dfsg-2.1build1 [460 kB]
516s Get:39 http://ftpmaster.internal/ubuntu oracular/main armhf zlib1g-dev armhf 1:1.3.dfsg-3.1ubuntu2 [880 kB]
516s Fetched 55.0 MB in 2s (25.4 MB/s)
516s Selecting previously unselected package libc-dev-bin.
516s (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 ... 58436 files and directories currently installed.)
516s Preparing to unpack .../00-libc-dev-bin_2.39-3.1ubuntu3_armhf.deb ...
516s Unpacking libc-dev-bin (2.39-3.1ubuntu3) ...
516s Selecting previously unselected package linux-libc-dev:armhf.
516s Preparing to unpack .../01-linux-libc-dev_6.8.0-31.31_armhf.deb ...
516s Unpacking linux-libc-dev:armhf (6.8.0-31.31) ...
516s Selecting previously unselected package libcrypt-dev:armhf.
516s Preparing to unpack .../02-libcrypt-dev_1%3a4.4.36-4build1_armhf.deb ...
516s Unpacking libcrypt-dev:armhf (1:4.4.36-4build1) ...
516s Selecting previously unselected package rpcsvc-proto.
516s Preparing to unpack .../03-rpcsvc-proto_1.4.2-0ubuntu7_armhf.deb ...
516s Unpacking rpcsvc-proto (1.4.2-0ubuntu7) ...
516s Selecting previously unselected package libc6-dev:armhf.
516s Preparing to unpack .../04-libc6-dev_2.39-3.1ubuntu3_armhf.deb ...
516s Unpacking libc6-dev:armhf (2.39-3.1ubuntu3) ...
517s Selecting previously unselected package gcc-13-base:armhf.
517s Preparing to unpack .../05-gcc-13-base_13.2.0-23ubuntu4_armhf.deb ...
517s Unpacking gcc-13-base:armhf (13.2.0-23ubuntu4) ...
517s Selecting previously unselected package libisl23:armhf.
517s Preparing to unpack .../06-libisl23_0.26-3build1_armhf.deb ...
517s Unpacking libisl23:armhf (0.26-3build1) ...
517s Selecting previously unselected package libmpc3:armhf.
517s Preparing to unpack .../07-libmpc3_1.3.1-1build1_armhf.deb ...
517s Unpacking libmpc3:armhf (1.3.1-1build1) ...
517s Selecting previously unselected package cpp-13-arm-linux-gnueabihf.
517s Preparing to unpack .../08-cpp-13-arm-linux-gnueabihf_13.2.0-23ubuntu4_armhf.deb ...
517s Unpacking cpp-13-arm-linux-gnueabihf (13.2.0-23ubuntu4) ...
517s Selecting previously unselected package cpp-13.
517s Preparing to unpack .../09-cpp-13_13.2.0-23ubuntu4_armhf.deb ...
517s Unpacking cpp-13 (13.2.0-23ubuntu4) ...
517s Selecting previously unselected package cpp-arm-linux-gnueabihf.
517s Preparing to unpack .../10-cpp-arm-linux-gnueabihf_4%3a13.2.0-7ubuntu1_armhf.deb ...
517s Unpacking cpp-arm-linux-gnueabihf (4:13.2.0-7ubuntu1) ...
517s Selecting previously unselected package cpp.
517s Preparing to unpack .../11-cpp_4%3a13.2.0-7ubuntu1_armhf.deb ...
517s Unpacking cpp (4:13.2.0-7ubuntu1) ...
517s Selecting previously unselected package libcc1-0:armhf.
517s Preparing to unpack .../12-libcc1-0_14.1.0-1ubuntu1_armhf.deb ...
517s Unpacking libcc1-0:armhf (14.1.0-1ubuntu1) ...
517s Selecting previously unselected package libgomp1:armhf.
517s Preparing to unpack .../13-libgomp1_14.1.0-1ubuntu1_armhf.deb ...
517s Unpacking libgomp1:armhf (14.1.0-1ubuntu1) ...
517s Selecting previously unselected package libatomic1:armhf.
517s Preparing to unpack .../14-libatomic1_14.1.0-1ubuntu1_armhf.deb ...
517s Unpacking libatomic1:armhf (14.1.0-1ubuntu1) ...
517s Selecting previously unselected package libasan8:armhf.
517s Preparing to unpack .../15-libasan8_14.1.0-1ubuntu1_armhf.deb ...
517s Unpacking libasan8:armhf (14.1.0-1ubuntu1) ...
517s Selecting previously unselected package libubsan1:armhf.
517s Preparing to unpack .../16-libubsan1_14.1.0-1ubuntu1_armhf.deb ...
517s Unpacking libubsan1:armhf (14.1.0-1ubuntu1) ...
517s Selecting previously unselected package libgcc-13-dev:armhf.
517s Preparing to unpack .../17-libgcc-13-dev_13.2.0-23ubuntu4_armhf.deb ...
517s Unpacking libgcc-13-dev:armhf (13.2.0-23ubuntu4) ...
517s Selecting previously unselected package gcc-13-arm-linux-gnueabihf.
517s Preparing to unpack .../18-gcc-13-arm-linux-gnueabihf_13.2.0-23ubuntu4_armhf.deb ...
517s Unpacking gcc-13-arm-linux-gnueabihf (13.2.0-23ubuntu4) ...
518s Selecting previously unselected package gcc-13.
518s Preparing to unpack .../19-gcc-13_13.2.0-23ubuntu4_armhf.deb ...
518s Unpacking gcc-13 (13.2.0-23ubuntu4) ...
518s Selecting previously unselected package gcc-arm-linux-gnueabihf.
518s Preparing to unpack .../20-gcc-arm-linux-gnueabihf_4%3a13.2.0-7ubuntu1_armhf.deb ...
518s Unpacking gcc-arm-linux-gnueabihf (4:13.2.0-7ubuntu1) ...
518s Selecting previously unselected package gcc.
518s Preparing to unpack .../21-gcc_4%3a13.2.0-7ubuntu1_armhf.deb ...
518s Unpacking gcc (4:13.2.0-7ubuntu1) ...
518s Selecting previously unselected package libstdc++-13-dev:armhf.
518s Preparing to unpack .../22-libstdc++-13-dev_13.2.0-23ubuntu4_armhf.deb ...
518s Unpacking libstdc++-13-dev:armhf (13.2.0-23ubuntu4) ...
518s Selecting previously unselected package g++-13-arm-linux-gnueabihf.
518s Preparing to unpack .../23-g++-13-arm-linux-gnueabihf_13.2.0-23ubuntu4_armhf.deb ...
518s Unpacking g++-13-arm-linux-gnueabihf (13.2.0-23ubuntu4) ...
518s Selecting previously unselected package g++-13.
518s Preparing to unpack .../24-g++-13_13.2.0-23ubuntu4_armhf.deb ...
518s Unpacking g++-13 (13.2.0-23ubuntu4) ...
518s Selecting previously unselected package g++-arm-linux-gnueabihf.
518s Preparing to unpack .../25-g++-arm-linux-gnueabihf_4%3a13.2.0-7ubuntu1_armhf.deb ...
518s Unpacking g++-arm-linux-gnueabihf (4:13.2.0-7ubuntu1) ...
518s Selecting previously unselected package g++.
518s Preparing to unpack .../26-g++_4%3a13.2.0-7ubuntu1_armhf.deb ...
518s Unpacking g++ (4:13.2.0-7ubuntu1) ...
518s Selecting previously unselected package build-essential.
518s Preparing to unpack .../27-build-essential_12.10ubuntu1_armhf.deb ...
518s Unpacking build-essential (12.10ubuntu1) ...
518s Selecting previously unselected package libblas3:armhf.
518s Preparing to unpack .../28-libblas3_3.12.0-3build1_armhf.deb ...
518s Unpacking libblas3:armhf (3.12.0-3build1) ...
518s Selecting previously unselected package libgfortran5:armhf.
518s Preparing to unpack .../29-libgfortran5_14.1.0-1ubuntu1_armhf.deb ...
518s Unpacking libgfortran5:armhf (14.1.0-1ubuntu1) ...
518s Selecting previously unselected package liblapack3:armhf.
518s Preparing to unpack .../30-liblapack3_3.12.0-3build1_armhf.deb ...
518s Unpacking liblapack3:armhf (3.12.0-3build1) ...
518s Selecting previously unselected package libslow5-0t64:armhf.
518s Preparing to unpack .../31-libslow5-0t64_0.7.0+dfsg-2.1build1_armhf.deb ...
518s Unpacking libslow5-0t64:armhf (0.7.0+dfsg-2.1build1) ...
518s Selecting previously unselected package libslow5-dev:armhf.
518s Preparing to unpack .../32-libslow5-dev_0.7.0+dfsg-2.1build1_armhf.deb ...
518s Unpacking libslow5-dev:armhf (0.7.0+dfsg-2.1build1) ...
519s Selecting previously unselected package libstreamvbyte0:armhf.
519s Preparing to unpack .../33-libstreamvbyte0_0.4.1-4ubuntu1_armhf.deb ...
519s Unpacking libstreamvbyte0:armhf (0.4.1-4ubuntu1) ...
519s Selecting previously unselected package libstreamvbyte-dev:armhf.
519s Preparing to unpack .../34-libstreamvbyte-dev_0.4.1-4ubuntu1_armhf.deb ...
519s Unpacking libstreamvbyte-dev:armhf (0.4.1-4ubuntu1) ...
519s Selecting previously unselected package python3-numpy.
519s Preparing to unpack .../35-python3-numpy_1%3a1.26.4+ds-10_armhf.deb ...
519s Unpacking python3-numpy (1:1.26.4+ds-10) ...
519s Selecting previously unselected package python3-slow5.
519s Preparing to unpack .../36-python3-slow5_0.7.0+dfsg-2.1build1_armhf.deb ...
519s Unpacking python3-slow5 (0.7.0+dfsg-2.1build1) ...
519s Selecting previously unselected package zlib1g-dev:armhf.
519s Preparing to unpack .../37-zlib1g-dev_1%3a1.3.dfsg-3.1ubuntu2_armhf.deb ...
519s Unpacking zlib1g-dev:armhf (1:1.3.dfsg-3.1ubuntu2) ...
519s Selecting previously unselected package autopkgtest-satdep.
519s Preparing to unpack .../38-2-autopkgtest-satdep.deb ...
519s Unpacking autopkgtest-satdep (0) ...
519s Setting up libstreamvbyte0:armhf (0.4.1-4ubuntu1) ...
519s Setting up linux-libc-dev:armhf (6.8.0-31.31) ...
519s Setting up libgomp1:armhf (14.1.0-1ubuntu1) ...
519s Setting up libblas3:armhf (3.12.0-3build1) ...
519s update-alternatives: using /usr/lib/arm-linux-gnueabihf/blas/libblas.so.3 to provide /usr/lib/arm-linux-gnueabihf/libblas.so.3 (libblas.so.3-arm-linux-gnueabihf) in auto mode
519s Setting up rpcsvc-proto (1.4.2-0ubuntu7) ...
519s Setting up gcc-13-base:armhf (13.2.0-23ubuntu4) ...
519s Setting up libstreamvbyte-dev:armhf (0.4.1-4ubuntu1) ...
519s Setting up libmpc3:armhf (1.3.1-1build1) ...
519s Setting up libatomic1:armhf (14.1.0-1ubuntu1) ...
519s Setting up libslow5-0t64:armhf (0.7.0+dfsg-2.1build1) ...
519s Setting up libgfortran5:armhf (14.1.0-1ubuntu1) ...
519s Setting up libubsan1:armhf (14.1.0-1ubuntu1) ...
519s Setting up libcrypt-dev:armhf (1:4.4.36-4build1) ...
519s Setting up libasan8:armhf (14.1.0-1ubuntu1) ...
519s Setting up libisl23:armhf (0.26-3build1) ...
519s Setting up libc-dev-bin (2.39-3.1ubuntu3) ...
519s Setting up libcc1-0:armhf (14.1.0-1ubuntu1) ...
519s Setting up liblapack3:armhf (3.12.0-3build1) ...
519s update-alternatives: using /usr/lib/arm-linux-gnueabihf/lapack/liblapack.so.3 to provide /usr/lib/arm-linux-gnueabihf/liblapack.so.3 (liblapack.so.3-arm-linux-gnueabihf) in auto mode
519s Setting up cpp-13-arm-linux-gnueabihf (13.2.0-23ubuntu4) ...
519s Setting up libslow5-dev:armhf (0.7.0+dfsg-2.1build1) ...
519s Setting up python3-numpy (1:1.26.4+ds-10) ...
521s Setting up libgcc-13-dev:armhf (13.2.0-23ubuntu4) ...
521s Setting up libc6-dev:armhf (2.39-3.1ubuntu3) ...
521s Setting up cpp-arm-linux-gnueabihf (4:13.2.0-7ubuntu1) ...
521s Setting up libstdc++-13-dev:armhf (13.2.0-23ubuntu4) ...
521s Setting up cpp-13 (13.2.0-23ubuntu4) ...
521s Setting up gcc-13-arm-linux-gnueabihf (13.2.0-23ubuntu4) ...
521s Setting up gcc-13 (13.2.0-23ubuntu4) ...
521s Setting up python3-slow5 (0.7.0+dfsg-2.1build1) ...
521s Setting up zlib1g-dev:armhf (1:1.3.dfsg-3.1ubuntu2) ...
521s Setting up cpp (4:13.2.0-7ubuntu1) ...
521s Setting up gcc-arm-linux-gnueabihf (4:13.2.0-7ubuntu1) ...
521s Setting up g++-13-arm-linux-gnueabihf (13.2.0-23ubuntu4) ...
521s Setting up g++-arm-linux-gnueabihf (4:13.2.0-7ubuntu1) ...
521s Setting up g++-13 (13.2.0-23ubuntu4) ...
521s Setting up gcc (4:13.2.0-7ubuntu1) ...
521s Setting up g++ (4:13.2.0-7ubuntu1) ...
521s update-alternatives: using /usr/bin/g++ to provide /usr/bin/c++ (c++) in auto mode
521s Setting up build-essential (12.10ubuntu1) ...
521s Setting up autopkgtest-satdep (0) ...
521s Processing triggers for man-db (2.12.1-2) ...
522s Processing triggers for libc-bin (2.39-3.1ubuntu3) ...
538s (Reading database ... 62115 files and directories currently installed.)
538s Removing autopkgtest-satdep (0) ...
551s autopkgtest [22:55:28]: test run-pkg-test: [-----------------------
553s Checking unit_test_ascii.c
554s Done!
554s Checking unit_test_binary.c
554s Done!
554s Checking unit_test_empty.c
554s Done!
554s Checking unit_test_enum.c
554s Done!
554s Checking unit_test_helpers.c
555s Done!
555s Checking unit_test_lossless.c
555s Done!
555s Checking unit_test_press.c
555s Done!
555s Checking unit_test_two_rg.c
555s Done!
555s autopkgtest [22:55:32]: test run-pkg-test: -----------------------]
560s autopkgtest [22:55:37]: test run-pkg-test:  - - - - - - - - - - results - - - - - - - - - -
560s run-pkg-test         PASS
563s autopkgtest [22:55:40]: @@@@@@@@@@@@@@@@@@@@ summary
563s run-pybinding-test   PASS
563s run-pkg-test         PASS