0s autopkgtest [16:11:37]: starting date and time: 2024-11-14 16:11:37+0000 0s autopkgtest [16:11:37]: git checkout: 6f3be7a8 Fix armhf LXD image generation for plucky 0s autopkgtest [16:11:37]: host juju-7f2275-prod-proposed-migration-environment-20; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work._qubr39m/out --timeout-copy=6000 --setup-commands /home/ubuntu/autopkgtest-cloud/worker-config-production/setup-canonical.sh --apt-pocket=proposed=src:numpy --apt-upgrade libslow5lib --timeout-short=300 --timeout-copy=20000 --timeout-build=20000 --env=ADT_TEST_TRIGGERS=numpy/1:1.26.4+ds-11ubuntu1 -- ssh -s /home/ubuntu/autopkgtest/ssh-setup/nova -- --flavor autopkgtest --security-groups autopkgtest-juju-7f2275-prod-proposed-migration-environment-20@bos03-arm64-15.secgroup --name adt-plucky-arm64-libslow5lib-20241114-161137-juju-7f2275-prod-proposed-migration-environment-20-dbf400bb-2650-4bd0-9b49-ee77208fc34d --image adt/ubuntu-plucky-arm64-server --keyname testbed-juju-7f2275-prod-proposed-migration-environment-20 --net-id=net_prod-proposed-migration -e TERM=linux -e ''"'"'http_proxy=http://squid.internal:3128'"'"'' -e ''"'"'https_proxy=http://squid.internal:3128'"'"'' -e ''"'"'no_proxy=127.0.0.1,127.0.1.1,login.ubuntu.com,localhost,localdomain,novalocal,internal,archive.ubuntu.com,ports.ubuntu.com,security.ubuntu.com,ddebs.ubuntu.com,changelogs.ubuntu.com,keyserver.ubuntu.com,launchpadlibrarian.net,launchpadcontent.net,launchpad.net,10.24.0.0/24,keystone.ps5.canonical.com,objectstorage.prodstack5.canonical.com'"'"'' --mirror=http://ftpmaster.internal/ubuntu/ 73s autopkgtest [16:12:50]: testbed dpkg architecture: arm64 74s autopkgtest [16:12:51]: testbed apt version: 2.9.8 74s autopkgtest [16:12:51]: @@@@@@@@@@@@@@@@@@@@ test bed setup 75s Get:1 http://ftpmaster.internal/ubuntu plucky-proposed InRelease [73.9 kB] 75s Get:2 http://ftpmaster.internal/ubuntu plucky-proposed/restricted Sources [7016 B] 75s Get:3 http://ftpmaster.internal/ubuntu plucky-proposed/multiverse Sources [15.3 kB] 75s Get:4 http://ftpmaster.internal/ubuntu plucky-proposed/universe Sources [966 kB] 75s Get:5 http://ftpmaster.internal/ubuntu plucky-proposed/main Sources [105 kB] 75s Get:6 http://ftpmaster.internal/ubuntu plucky-proposed/main arm64 Packages [138 kB] 75s Get:7 http://ftpmaster.internal/ubuntu plucky-proposed/restricted arm64 Packages [50.3 kB] 75s Get:8 http://ftpmaster.internal/ubuntu plucky-proposed/universe arm64 Packages [724 kB] 75s Get:9 http://ftpmaster.internal/ubuntu plucky-proposed/multiverse arm64 Packages [6012 B] 75s Fetched 2085 kB in 1s (2283 kB/s) 75s Reading package lists... 78s Reading package lists... 78s Building dependency tree... 78s Reading state information... 79s Calculating upgrade... 80s The following packages will be upgraded: 80s pastebinit python3-systemd 80s 2 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 80s Need to get 61.6 kB of archives. 80s After this operation, 347 kB of additional disk space will be used. 80s Get:1 http://ftpmaster.internal/ubuntu plucky/main arm64 pastebinit all 1.7.1-1 [14.9 kB] 80s Get:2 http://ftpmaster.internal/ubuntu plucky/main arm64 python3-systemd arm64 235-1build5 [46.7 kB] 80s Fetched 61.6 kB in 0s (178 kB/s) 81s (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 ... 79925 files and directories currently installed.) 81s Preparing to unpack .../pastebinit_1.7.1-1_all.deb ... 81s Unpacking pastebinit (1.7.1-1) over (1.7.0-1) ... 81s Preparing to unpack .../python3-systemd_235-1build5_arm64.deb ... 81s Unpacking python3-systemd (235-1build5) over (235-1build4) ... 81s Setting up pastebinit (1.7.1-1) ... 81s Setting up python3-systemd (235-1build5) ... 81s Processing triggers for man-db (2.12.1-3) ... 82s Reading package lists... 82s Building dependency tree... 82s Reading state information... 83s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 83s Hit:1 http://ftpmaster.internal/ubuntu plucky-proposed InRelease 83s Hit:2 http://ftpmaster.internal/ubuntu plucky InRelease 83s Hit:3 http://ftpmaster.internal/ubuntu plucky-updates InRelease 83s Hit:4 http://ftpmaster.internal/ubuntu plucky-security InRelease 85s Reading package lists... 85s Reading package lists... 85s Building dependency tree... 85s Reading state information... 86s Calculating upgrade... 86s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 87s Reading package lists... 87s Building dependency tree... 87s Reading state information... 88s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 91s autopkgtest [16:13:08]: testbed running kernel: Linux 6.11.0-8-generic #8-Ubuntu SMP PREEMPT_DYNAMIC Mon Sep 16 14:19:41 UTC 2024 91s autopkgtest [16:13:08]: @@@@@@@@@@@@@@@@@@@@ apt-source libslow5lib 94s Get:1 http://ftpmaster.internal/ubuntu plucky/universe libslow5lib 0.7.0+dfsg-3 (dsc) [2584 B] 94s Get:2 http://ftpmaster.internal/ubuntu plucky/universe libslow5lib 0.7.0+dfsg-3 (tar) [2014 kB] 94s Get:3 http://ftpmaster.internal/ubuntu plucky/universe libslow5lib 0.7.0+dfsg-3 (diff) [8348 B] 94s gpgv: Signature made Wed Jul 24 20:44:11 2024 UTC 94s gpgv: using RSA key 8F91B227C7D6F2B1948C8236793CF67E8F0D11DA 94s gpgv: issuer "emollier@debian.org" 94s gpgv: Can't check signature: No public key 94s dpkg-source: warning: cannot verify inline signature for ./libslow5lib_0.7.0+dfsg-3.dsc: no acceptable signature found 94s autopkgtest [16:13:11]: testing package libslow5lib version 0.7.0+dfsg-3 95s autopkgtest [16:13:12]: build not needed 96s autopkgtest [16:13:13]: test run-pybinding-test: preparing testbed 99s Reading package lists... 99s Building dependency tree... 99s Reading state information... 100s Starting pkgProblemResolver with broken count: 0 100s Starting 2 pkgProblemResolver with broken count: 0 100s Done 100s The following additional packages will be installed: 100s libblas3 libgfortran5 liblapack3 libslow5-0t64 libslow5-dev libstreamvbyte0 100s python3-all python3-numpy python3-slow5 101s Suggested packages: 101s gcc gfortran python-numpy-doc python3-dev python3-pytest 101s The following NEW packages will be installed: 101s autopkgtest-satdep libblas3 libgfortran5 liblapack3 libslow5-0t64 101s libslow5-dev libstreamvbyte0 python3-all python3-numpy python3-slow5 101s 0 upgraded, 10 newly installed, 0 to remove and 0 not upgraded. 101s Need to get 7643 kB/7644 kB of archives. 101s After this operation, 43.7 MB of additional disk space will be used. 101s Get:1 /tmp/autopkgtest.AGrcur/1-autopkgtest-satdep.deb autopkgtest-satdep arm64 0 [732 B] 101s Get:2 http://ftpmaster.internal/ubuntu plucky/main arm64 libblas3 arm64 3.12.0-3build2 [152 kB] 101s Get:3 http://ftpmaster.internal/ubuntu plucky/main arm64 libgfortran5 arm64 14.2.0-8ubuntu1 [438 kB] 101s Get:4 http://ftpmaster.internal/ubuntu plucky/main arm64 liblapack3 arm64 3.12.0-3build2 [2293 kB] 101s Get:5 http://ftpmaster.internal/ubuntu plucky/universe arm64 libslow5-0t64 arm64 0.7.0+dfsg-3 [61.9 kB] 101s Get:6 http://ftpmaster.internal/ubuntu plucky/universe arm64 libslow5-dev arm64 0.7.0+dfsg-3 [90.4 kB] 101s Get:7 http://ftpmaster.internal/ubuntu plucky/universe arm64 libstreamvbyte0 arm64 0.4.1-4ubuntu1 [6260 B] 101s Get:8 http://ftpmaster.internal/ubuntu plucky/main arm64 python3-all arm64 3.12.6-0ubuntu1 [886 B] 101s Get:9 http://ftpmaster.internal/ubuntu plucky-proposed/main arm64 python3-numpy arm64 1:1.26.4+ds-11ubuntu1 [4149 kB] 101s Get:10 http://ftpmaster.internal/ubuntu plucky/universe arm64 python3-slow5 arm64 0.7.0+dfsg-3 [452 kB] 102s Fetched 7643 kB in 1s (9783 kB/s) 102s Selecting previously unselected package libblas3:arm64. 102s (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 ... 79930 files and directories currently installed.) 102s Preparing to unpack .../0-libblas3_3.12.0-3build2_arm64.deb ... 102s Unpacking libblas3:arm64 (3.12.0-3build2) ... 102s Selecting previously unselected package libgfortran5:arm64. 102s Preparing to unpack .../1-libgfortran5_14.2.0-8ubuntu1_arm64.deb ... 102s Unpacking libgfortran5:arm64 (14.2.0-8ubuntu1) ... 102s Selecting previously unselected package liblapack3:arm64. 102s Preparing to unpack .../2-liblapack3_3.12.0-3build2_arm64.deb ... 102s Unpacking liblapack3:arm64 (3.12.0-3build2) ... 102s Selecting previously unselected package libslow5-0t64:arm64. 102s Preparing to unpack .../3-libslow5-0t64_0.7.0+dfsg-3_arm64.deb ... 102s Unpacking libslow5-0t64:arm64 (0.7.0+dfsg-3) ... 102s Selecting previously unselected package libslow5-dev:arm64. 102s Preparing to unpack .../4-libslow5-dev_0.7.0+dfsg-3_arm64.deb ... 102s Unpacking libslow5-dev:arm64 (0.7.0+dfsg-3) ... 102s Selecting previously unselected package libstreamvbyte0:arm64. 102s Preparing to unpack .../5-libstreamvbyte0_0.4.1-4ubuntu1_arm64.deb ... 102s Unpacking libstreamvbyte0:arm64 (0.4.1-4ubuntu1) ... 102s Selecting previously unselected package python3-all. 102s Preparing to unpack .../6-python3-all_3.12.6-0ubuntu1_arm64.deb ... 102s Unpacking python3-all (3.12.6-0ubuntu1) ... 102s Selecting previously unselected package python3-numpy. 102s Preparing to unpack .../7-python3-numpy_1%3a1.26.4+ds-11ubuntu1_arm64.deb ... 102s Unpacking python3-numpy (1:1.26.4+ds-11ubuntu1) ... 102s Selecting previously unselected package python3-slow5. 102s Preparing to unpack .../8-python3-slow5_0.7.0+dfsg-3_arm64.deb ... 102s Unpacking python3-slow5 (0.7.0+dfsg-3) ... 102s Selecting previously unselected package autopkgtest-satdep. 102s Preparing to unpack .../9-1-autopkgtest-satdep.deb ... 102s Unpacking autopkgtest-satdep (0) ... 102s Setting up libstreamvbyte0:arm64 (0.4.1-4ubuntu1) ... 102s Setting up python3-all (3.12.6-0ubuntu1) ... 102s Setting up libblas3:arm64 (3.12.0-3build2) ... 103s update-alternatives: using /usr/lib/aarch64-linux-gnu/blas/libblas.so.3 to provide /usr/lib/aarch64-linux-gnu/libblas.so.3 (libblas.so.3-aarch64-linux-gnu) in auto mode 103s Setting up libslow5-0t64:arm64 (0.7.0+dfsg-3) ... 103s Setting up libgfortran5:arm64 (14.2.0-8ubuntu1) ... 103s Setting up liblapack3:arm64 (3.12.0-3build2) ... 103s update-alternatives: using /usr/lib/aarch64-linux-gnu/lapack/liblapack.so.3 to provide /usr/lib/aarch64-linux-gnu/liblapack.so.3 (liblapack.so.3-aarch64-linux-gnu) in auto mode 103s Setting up libslow5-dev:arm64 (0.7.0+dfsg-3) ... 103s Setting up python3-numpy (1:1.26.4+ds-11ubuntu1) ... 105s Setting up python3-slow5 (0.7.0+dfsg-3) ... 105s Setting up autopkgtest-satdep (0) ... 105s Processing triggers for man-db (2.12.1-3) ... 105s Processing triggers for libc-bin (2.40-1ubuntu3) ... 109s (Reading database ... 80887 files and directories currently installed.) 109s Removing autopkgtest-satdep (0) ... 109s autopkgtest [16:13:26]: test run-pybinding-test: [----------------------- 110s Testing with python3.12 in /tmp/autopkgtest.AGrcur/autopkgtest_tmp: 110s 14-Nov-24 16:13:27 - [DEBUG]: FILE: examples/example.slow5, mode: r 110s 14-Nov-24 16:13:27 - [DEBUG]: FILE: b'examples/example.slow5', mode: b'r' 110s 14-Nov-24 16:13:27 - [DEBUG]: Number of read_groups: 1 110s 14-Nov-24 16:13:27 - [DEBUG]: FILE: examples/example.slow5, mode: r 110s 14-Nov-24 16:13:27 - [DEBUG]: Creating/loading index... 110s [slow5_idx_init::INFO] Index file not found. Creating an index at 'examples/example.slow5.idx'. 110s 14-Nov-24 16:13:27 - [DEBUG]: get_aux_names starting 110s 14-Nov-24 16:13:27 - [DEBUG]: get_aux_names aux_len: 0 110s 14-Nov-24 16:13:27 - [WARNING]: get_aux_names ret is NULL 110s 14-Nov-24 16:13:27 - [DEBUG]: get_aux_types starting 110s 14-Nov-24 16:13:27 - [DEBUG]: get_aux_types aux_len: 0 110s 14-Nov-24 16:13:27 - [WARNING]: get_aux_types self.s5_aux_type is NULL 110s 14-Nov-24 16:13:27 - [WARNING]: get_read unknown aux name: read_number 110s 14-Nov-24 16:13:27 - [WARNING]: get_read unknown aux name: start_mux 110s 14-Nov-24 16:13:27 - [WARNING]: get_read unknown aux name: blah 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: -1 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next reached end of file (EOF)(-1): -1: ['SLOW5_ERR_EOF', 'End Of File reached'] 110s [slow5_idx_get::ERROR] Read ID 'null_read' was not found. At src/slow5_idx.c:441 110s 14-Nov-24 16:13:27 - [DEBUG]: get_read return not 0: -7 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_hdr_keys head_len: 32 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_hdr_keys head_len: 32 110s 14-Nov-24 16:13:27 - [DEBUG]: examples/example.slow5 closed 110s 14-Nov-24 16:13:27 - [DEBUG]: FILE: examples/example2.slow5, mode: r 110s 14-Nov-24 16:13:27 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r' 110s 14-Nov-24 16:13:27 - [DEBUG]: Number of read_groups: 4 110s 14-Nov-24 16:13:27 - [DEBUG]: FILE: examples/example2.slow5, mode: r 110s 14-Nov-24 16:13:27 - [DEBUG]: Creating/loading index... 110s [slow5_idx_init::INFO] Index file not found. Creating an index at 'examples/example2.slow5.idx'. 110s 14-Nov-24 16:13:27 - [DEBUG]: get_aux_names starting 110s 14-Nov-24 16:13:27 - [DEBUG]: get_aux_names aux_len: 5 110s 14-Nov-24 16:13:27 - [DEBUG]: get_aux_types starting 110s 14-Nov-24 16:13:27 - [DEBUG]: get_aux_types aux_len: 5 110s 14-Nov-24 16:13:27 - [WARNING]: get_read unknown aux name: blah 110s 14-Nov-24 16:13:27 - [WARNING]: get_read unknown aux name: blah 110s 14-Nov-24 16:13:27 - [DEBUG]: get_aux_names starting 110s 14-Nov-24 16:13:27 - [DEBUG]: get_aux_names aux_len: 5 110s 14-Nov-24 16:13:27 - [DEBUG]: get_aux_types starting 110s 14-Nov-24 16:13:27 - [DEBUG]: get_aux_types aux_len: 5 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: -1 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next reached end of file (EOF)(-1): -1: ['SLOW5_ERR_EOF', 'End Of File reached'] 110s 14-Nov-24 16:13:27 - [DEBUG]: examples/example2.slow5 closed 110s 14-Nov-24 16:13:27 - [DEBUG]: FILE: examples/example_write.slow5, mode: w 110s 14-Nov-24 16:13:27 - [DEBUG]: FILE: b'examples/example_write.slow5', mode: b'w' 110s 14-Nov-24 16:13:27 - [DEBUG]: Not writing blow5, skipping compression steps 110s 14-Nov-24 16:13:27 - [DEBUG]: FILE: examples/example2.slow5, mode: r 110s 14-Nov-24 16:13:27 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r' 110s 14-Nov-24 16:13:27 - [DEBUG]: Number of read_groups: 4 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation running 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checking header stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: writting header... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: header written 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() ret: 305872 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_free() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: function complete, returning 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation running 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() ret: 152707 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_free() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: function complete, returning 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation running 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() ret: 305872 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_free() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: function complete, returning 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation running 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() ret: 152707 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_free() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: function complete, returning 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation running 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() ret: 305872 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_free() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: function complete, returning 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation running 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() ret: 152707 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_free() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: function complete, returning 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation running 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() ret: 305906 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_free() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: function complete, returning 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation running 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() ret: 152741 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_free() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: function complete, returning 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: -1 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next reached end of file (EOF)(-1): -1: ['SLOW5_ERR_EOF', 'End Of File reached'] 110s 14-Nov-24 16:13:27 - [DEBUG]: examples/example_write.slow5 closed 110s 14-Nov-24 16:13:27 - [DEBUG]: examples/example2.slow5 closed 110s 14-Nov-24 16:13:27 - [DEBUG]: FILE: examples/example_write_append.blow5, mode: w 110s 14-Nov-24 16:13:27 - [DEBUG]: FILE: b'examples/example_write_append.blow5', mode: b'w' 110s 14-Nov-24 16:13:27 - [DEBUG]: examples/example_write.slow5 already closed 110s 14-Nov-24 16:13:27 - [DEBUG]: pathname: examples/example_write.slow5 110s 14-Nov-24 16:13:27 - [DEBUG]: total_time_slow5_get_next: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_time_yield_reads: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_single_write_time: 0.027689695358276367 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_multi_write_time: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: FILE: examples/example2.slow5, mode: r 110s 14-Nov-24 16:13:27 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r' 110s 14-Nov-24 16:13:27 - [DEBUG]: Number of read_groups: 4 110s 14-Nov-24 16:13:27 - [DEBUG]: pathname: examples/example2.slow5 110s 14-Nov-24 16:13:27 - [DEBUG]: total_time_slow5_get_next: 0.017217159271240234 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_time_yield_reads: 0.018497705459594727 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_single_write_time: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_multi_write_time: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation running 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checking header stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: writting header... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: header written 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() ret: 152976 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_free() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: function complete, returning 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation running 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() ret: 76384 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_free() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: function complete, returning 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation running 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() ret: 152976 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_free() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: function complete, returning 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation running 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() ret: 76384 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_free() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: function complete, returning 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation running 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() ret: 152976 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_free() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: function complete, returning 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation running 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() ret: 76384 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_free() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: function complete, returning 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation running 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() ret: 153010 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_free() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: function complete, returning 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation running 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() ret: 76418 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_free() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: function complete, returning 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: -1 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next reached end of file (EOF)(-1): -1: ['SLOW5_ERR_EOF', 'End Of File reached'] 110s 14-Nov-24 16:13:27 - [DEBUG]: examples/example2.slow5 closed 110s 14-Nov-24 16:13:27 - [DEBUG]: examples/example_write_append.blow5 closed 110s 14-Nov-24 16:13:27 - [DEBUG]: FILE: examples/example_write_append.blow5, mode: a 110s 14-Nov-24 16:13:27 - [DEBUG]: FILE: b'examples/example_write_append.blow5', mode: b'a' 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_hdr_keys head_len: 38 110s |==============================================| 110s | pyslow5 test launch | 110s |==============================================| 110s ['__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'] 110s slow5 file opened and object created in: 0.0007 seconds 110s ============================================== 110s get_read check, r1 110s get_read in: 0.0042 seconds 110s read_id: r1 110s read_group: 0 110s digitisation: 8192.0 110s offset: 23.0 110s range: 1467.61 110s sampling_rate: 4000.0 110s len_raw_signal: 59676 110s signal: [1039 588 588 593 586 574 570 585 588 586] 110s pylen of signal: 59676 110s AUX FIELDS: 110s read_number: None 110s start_mux: None 110s blah: None 110s ============================================== 110s get_read check, r4, converte to pA 110s get_read in: 0.0063 seconds 110s read_id: r4 110s read_group: 0 110s digitisation: 8192.0 110s offset: 23.0 110s range: 1467.61 110s sampling_rate: 4000.0 110s len_raw_signal: 59670 110s signal: [190.25902 108.92418 109.46163 109.10333 107.67012 108.38673 110s 108.745026 109.10333 111.074 108.38673 ] 110s pylen of signal: 59670 110s signal value type: 110s ============================================== 110s seq_reads check, all reads 110s seq_reads readIDs: 110s type check reads: 110s r1 110s r2 110s r3 110s r4 110s r5 110s seq_reads in: 0.0124 seconds 110s ============================================== 110s Yield check, selected reads 110s get_read_list in: 0.0 seconds 110s yielded readIDs: 110s r1 r1 110s r3 r3 110s null_read read not found, None returned 110s r5 r5 110s r2 r2 110s r1 r1 110s ============================================== 110s Get headder names 110s header names: 110s ['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'] 110s ============================================== 110s get_all_headers 110s {'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'} 110s ============================================== 110s Get headder attributes 110s flow_cell_id: FAB43577 110s exp_start_time: 1479433093 110s heatsink_temp: 33.9921875 110s asic_id: 3574887596 110s asic_id_eeprom: 0 110s asic_temp: 29.2145729 110s auto_update: 1 110s auto_update_source: https://mirror.oxfordnanoportal.com/software/MinKNOW/ 110s bream_core_version: 1.1.20.1 110s bream_is_standard: 1 110s bream_map_version: 1.1.20.1 110s bream_ont_version: 1.1.20.1 110s bream_prod_version: 1.1.20.1 110s bream_rnd_version: 0.1.1 110s device_id: MN16450 110s exp_script_name: python/recipes/nc/NC_48Hr_Sequencing_Run_FLO-MIN106_SQK-LSK108.py 110s exp_script_purpose: sequencing_run 110s exp_start_time: 1479433093 110s experiment_kit: genomic_dna 110s experiment_type: customer_qc 110s file_version: 1 110s filename: deamernanopore_20161117_fnfab43577_mn16450_sequencing_run_ma_821_r9_4_na12878_11_17_16_88738 110s flow_cell_id: FAB43577 110s heatsink_temp: 33.9921875 110s hostname: DEAMERNANOPORE 110s installation_type: map 110s local_firmware_file: 0 110s operating_system: Windows 6.2 110s protocol_run_id: a4429838-103c-497f-a824-7dffa72cfd81 110s protocols_version: 1.1.20 110s run_id: d6e473a6d513ec6bfc150c60fd4556d72f0e6d18 110s sample_frequency: 4000 110s usb_config: 1.0.11_ONT#MinION_fpga_1.0.1#ctrl#Auto 110s user_filename_input: ma_821_r9.4_na12878_11_17_16 110s version: 1.1.20 110s ============================================== 110s get_read check, 0d624d4b-671f-40b8-9798-84f2ccc4d7fc 110s read_id: 0d624d4b-671f-40b8-9798-84f2ccc4d7fc 110s read_group: 3 110s digitisation: 8192.0 110s offset: 6.0 110s range: 1444.86 110s sampling_rate: 4000.0 110s len_raw_signal: 38164 110s signal: [1462 1075 795 801 797 788 817 791 801 802] 110s pylen of signal: 38164 110s AUX FIELDS: 110s read_number: 2287 110s start_mux: 2 110s blah: None 110s AUX FIELDS: 110s blah: None 110s AUX FIELDS: 110s read_number: 2287 110s ============================================== 110s Get aux names 110s aux names: 110s ['channel_number', 'median_before', 'read_number', 'start_mux', 'start_time'] 110s ============================================== 110s Get aux types 110s aux types: 110s [22, 9, 2, 4, 7] 110s ============================================== 110s AUX FIELDS: 110s channel_number: 391 110s median_before: 260.557264 110s read_number: 2287 110s start_mux: 2 110s start_time: 36886851 110s ============================================== 110s seq_reads with aux: 110s type check reads: 110s r0 110s read_number 4019 110s r1 110s read_number 2287 110s r2 110s read_number 4019 110s r3 110s read_number 2287 110s r4 110s read_number 4019 110s r5 110s read_number 2287 110s 0a238451-b9ed-446d-a152-badd074006c4 110s read_number 4019 110s 0d624d4b-671f-40b8-9798-84f2ccc4d7fc 110s read_number 2287 110s ============================================== 110s write reads no aux 110s ret: write_header(): 0 110s ret: write_record(): 0 110s ret: write_record(): 0 110s ret: write_record(): 0 110s ret: write_record(): 0 110s ret: write_record(): 0 110s ret: write_record(): 0 110s ret: write_record(): 0 110s ret: write_record(): 0 110s ============================================== 110s append reads no aux 110s ret: write_header(): 0 110s ret: write_record(): 0 110s ret: write_record(): 0 110s ret: write_record(): 0 110s ret: write_record(): 0 110s ret: write_record(): 0 110s ret: write_record(): 0 110s ret: write_record(): 0 110s ret: write_record(): 0 110s get_all_headers 110s {'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'}14-Nov-24 16:13:27 - [DEBUG]: FILE: examples/example2.slow5, mode: r 110s 14-Nov-24 16:13:27 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r' 110s 14-Nov-24 16:13:27 - [DEBUG]: Number of read_groups: 4 110s 14-Nov-24 16:13:27 - [DEBUG]: pathname: examples/example2.slow5 110s 14-Nov-24 16:13:27 - [DEBUG]: total_time_slow5_get_next: 0.017277240753173828 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_time_yield_reads: 0.018500566482543945 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_single_write_time: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_multi_write_time: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation running 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() ret: 152983 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_free() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: function complete, returning 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation running 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() ret: 76391 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_free() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: function complete, returning 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation running 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() ret: 152983 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_free() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: function complete, returning 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation running 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() ret: 76391 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_free() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: function complete, returning 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation running 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() ret: 152983 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_free() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: function complete, returning 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation running 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() ret: 76391 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_free() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: function complete, returning 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation running 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() ret: 153017 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_free() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: function complete, returning 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation running 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() ret: 76425 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_free() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: function complete, returning 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: -1 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next reached end of file (EOF)(-1): -1: ['SLOW5_ERR_EOF', 'End Of File reached'] 110s 14-Nov-24 16:13:27 - [DEBUG]: examples/example2.slow5 closed 110s 14-Nov-24 16:13:27 - [DEBUG]: examples/example_write_append.blow5 closed 110s 14-Nov-24 16:13:27 - [DEBUG]: FILE: examples/example_write_aux.blow5, mode: w 110s 14-Nov-24 16:13:27 - [DEBUG]: FILE: b'examples/example_write_aux.blow5', mode: b'w' 110s 14-Nov-24 16:13:27 - [DEBUG]: examples/example_write_append.blow5 already closed 110s 14-Nov-24 16:13:27 - [DEBUG]: pathname: examples/example_write_append.blow5 110s 14-Nov-24 16:13:27 - [DEBUG]: total_time_slow5_get_next: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_time_yield_reads: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_single_write_time: 0.02747821807861328 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_multi_write_time: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: FILE: examples/example2.slow5, mode: r 110s 14-Nov-24 16:13:27 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r' 110s 14-Nov-24 16:13:27 - [DEBUG]: Number of read_groups: 4 110s 14-Nov-24 16:13:27 - [DEBUG]: pathname: examples/example2.slow5 110s 14-Nov-24 16:13:27 - [DEBUG]: total_time_slow5_get_next: 0.01719522476196289 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_time_yield_reads: 0.01852250099182129 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_single_write_time: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_multi_write_time: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: get_aux_names starting 110s 14-Nov-24 16:13:27 - [DEBUG]: get_aux_names aux_len: 5 110s 14-Nov-24 16:13:27 - [DEBUG]: get_aux_types starting 110s 14-Nov-24 16:13:27 - [DEBUG]: get_aux_types aux_len: 5 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation running 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checking header stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: writting header... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: header written 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: channel_number: 281 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string running... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string type: 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: median_before: 231.363533 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: read_number: 4019 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: start_mux: 1 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: start_time: 78470500 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: aux stuff done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() ret: 67258 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_free() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: function complete, returning 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation running 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: channel_number: 391 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string running... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string type: 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: median_before: 260.557264 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: read_number: 2287 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: start_mux: 2 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: start_time: 36886851 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: aux stuff done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() ret: 32408 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_free() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: function complete, returning 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation running 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: channel_number: 281 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string running... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string type: 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: median_before: 231.363533 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: read_number: 4019 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: start_mux: 1 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: start_time: 78470500 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: aux stuff done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() ret: 67258 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_free() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: function complete, returning 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation running 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: channel_number: 391 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string running... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string type: 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: median_before: 260.557264 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: read_number: 2287 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: start_mux: 2 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: start_time: 36886851 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: aux stuff done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() ret: 32408 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_free() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: function complete, returning 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation running 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: channel_number: 281 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string running... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string type: 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: median_before: 231.363533 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: read_number: 4019 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: start_mux: 1 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: start_time: 78470500 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: aux stuff done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() ret: 67260 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_free() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: function complete, returning 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation running 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: channel_number: 391 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string running... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string type: 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: median_before: 260.557264 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: read_number: 2287 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: start_mux: 2 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: start_time: 36886851 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: aux stuff done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() ret: 32408 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_free() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: function complete, returning 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation running 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: channel_number: 281 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string running... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string type: 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: median_before: 231.363533 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: read_number: 4019 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: start_mux: 1 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: start_time: 78470500 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: aux stuff done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() ret: 67298 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_free() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: function complete, returning 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation running 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: channel_number: 391 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string running... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string type: 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: median_before: 260.557264 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: read_number: 2287 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: start_mux: 2 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: start_time: 36886851 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: aux stuff done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() ret: 32446 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_free() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: function complete, returning 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: -1 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next reached end of file (EOF)(-1): -1: ['SLOW5_ERR_EOF', 'End Of File reached'] 110s 14-Nov-24 16:13:27 - [DEBUG]: examples/example2.slow5 closed 110s 14-Nov-24 16:13:27 - [DEBUG]: examples/example_write_aux.blow5 closed 110s 14-Nov-24 16:13:27 - [DEBUG]: FILE: examples/example_write_append_aux.blow5, mode: w 110s 14-Nov-24 16:13:27 - [DEBUG]: FILE: b'examples/example_write_append_aux.blow5', mode: b'w' 110s 14-Nov-24 16:13:27 - [DEBUG]: examples/example_write_aux.blow5 already closed 110s 14-Nov-24 16:13:27 - [DEBUG]: pathname: examples/example_write_aux.blow5 110s 14-Nov-24 16:13:27 - [DEBUG]: total_time_slow5_get_next: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_time_yield_reads: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_single_write_time: 0.027790069580078125 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_multi_write_time: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: FILE: examples/example2.slow5, mode: r 110s 14-Nov-24 16:13:27 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r' 110s 14-Nov-24 16:13:27 - [DEBUG]: Number of read_groups: 4 110s 14-Nov-24 16:13:27 - [DEBUG]: pathname: examples/example2.slow5 110s 14-Nov-24 16:13:27 - [DEBUG]: total_time_slow5_get_next: 0.01707315444946289 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_time_yield_reads: 0.01874399185180664 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_single_write_time: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_multi_write_time: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: get_aux_names starting 110s 14-Nov-24 16:13:27 - [DEBUG]: get_aux_names aux_len: 5 110s 14-Nov-24 16:13:27 - [DEBUG]: get_aux_types starting 110s 14-Nov-24 16:13:27 - [DEBUG]: get_aux_types aux_len: 5 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation running 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checking header stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: writting header... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: header written 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: channel_number: 281 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string running... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string type: 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: median_before: 231.363533 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: read_number: 4019 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: start_mux: 1 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: start_time: 78470500 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: aux stuff done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() ret: 153008 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_free() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: function complete, returning 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation running 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: channel_number: 391 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string running... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string type: 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: median_before: 260.557264 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: read_number: 2287 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: start_mux: 2 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: start_time: 36886851 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: aux stuff done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() ret: 76416 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_free() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: function complete, returning 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation running 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: channel_number: 281 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string running... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string type: 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: median_before: 231.363533 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: read_number: 4019 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: start_mux: 1 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: start_time: 78470500 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: aux stuff done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() ret: 153008 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_free() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: function complete, returning 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation running 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: channel_number: 391 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string running... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string type: 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: median_before: 260.557264 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: read_number: 2287 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: start_mux: 2 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: start_time: 36886851 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: aux stuff done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() ret: 76416 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_free() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: function complete, returning 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation running 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: channel_number: 281 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string running... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string type: 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: median_before: 231.363533 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: read_number: 4019 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: start_mux: 1 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: start_time: 78470500 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: aux stuff done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() ret: 153008 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_free() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: function complete, returning 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation running 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: channel_number: 391 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string running... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string type: 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: median_before: 260.557264 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: read_number: 2287 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: start_mux: 2 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: start_time: 36886851 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: aux stuff done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() ret: 76416 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_free() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: function complete, returning 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation running 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: channel_number: 281 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string running... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string type: 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: median_before: 231.363533 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: read_number: 4019 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: start_mux: 1 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: start_time: 78470500 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: aux stuff done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() ret: 153042 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_free() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: function complete, returning 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation running 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: channel_number: 391 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string running... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string type: 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: median_before: 260.557264 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: read_number: 2287 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: start_mux: 2 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: start_time: 36886851 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: aux stuff done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() ret: 76450 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_free() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: function complete, returning 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: -1 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next reached end of file (EOF)(-1): -1: ['SLOW5_ERR_EOF', 'End Of File reached'] 110s 14-Nov-24 16:13:27 - [DEBUG]: examples/example2.slow5 closed 110s 14-Nov-24 16:13:27 - [DEBUG]: examples/example_write_append_aux.blow5 closed 110s 14-Nov-24 16:13:27 - [DEBUG]: FILE: examples/example_write_append_aux.blow5, mode: a 110s 14-Nov-24 16:13:27 - [DEBUG]: FILE: b'examples/example_write_append_aux.blow5', mode: b'a' 110s 14-Nov-24 16:13:27 - [DEBUG]: examples/example_write_append.blow5 already closed 110s 14-Nov-24 16:13:27 - [DEBUG]: pathname: examples/example_write_append.blow5 110s 14-Nov-24 16:13:27 - [DEBUG]: total_time_slow5_get_next: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_time_yield_reads: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_single_write_time: 0.02786993980407715 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_multi_write_time: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: FILE: examples/example2.slow5, mode: r 110s 14-Nov-24 16:13:27 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r' 110s 14-Nov-24 16:13:27 - [DEBUG]: Number of read_groups: 4 110s 14-Nov-24 16:13:27 - [DEBUG]: pathname: examples/example2.slow5 110s 14-Nov-24 16:13:27 - [DEBUG]: total_time_slow5_get_next: 0.017176389694213867 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_time_yield_reads: 0.018764734268188477 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_single_write_time: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_multi_write_time: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: get_aux_names starting 110s 14-Nov-24 16:13:27 - [DEBUG]: get_aux_names aux_len: 5 110s 14-Nov-24 16:13:27 - [DEBUG]: get_aux_types starting 110s 14-Nov-24 16:13:27 - [DEBUG]: get_aux_types aux_len: 5 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation running 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: channel_number: 281 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string running... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string type: 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: median_before: 231.363533 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: read_number: 4019 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: start_mux: 1 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: start_time: 78470500 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: aux stuff done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() ret: 153015 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_free() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: function complete, returning 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation running 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: channel_number: 391 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string running... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string type: 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: median_before: 260.557264 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: read_number: 2287 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: start_mux: 2 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: start_time: 36886851 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: aux stuff done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() ret: 76423 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_free() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: function complete, returning 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation running 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: channel_number: 281 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string running... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string type: 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: median_before: 231.363533 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: read_number: 4019 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: start_mux: 1 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: start_time: 78470500 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: aux stuff done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() ret: 153015 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_free() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: function complete, returning 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation running 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: channel_number: 391 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string running... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string type: 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: median_before: 260.557264 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: read_number: 2287 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: start_mux: 2 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: start_time: 36886851 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: aux stuff done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() ret: 76423 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_free() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: function complete, returning 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation running 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: channel_number: 281 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string running... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string type: 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: median_before: 231.363533 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: read_number: 4019 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: start_mux: 1 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: start_time: 78470500 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: aux stuff done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() ret: 153015 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_free() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: function complete, returning 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation running 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: channel_number: 391 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string running... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string type: 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: median_before: 260.557264 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: read_number: 2287 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: start_mux: 2 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: start_time: 36886851 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: aux stuff done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() ret: 76423 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_free() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: function complete, returning 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation running 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: channel_number: 281 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string running... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string type: 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: median_before: 231.363533 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: read_number: 4019 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: start_mux: 1 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: start_time: 78470500 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: aux stuff done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() ret: 153049 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_free() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: function complete, returning 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation running 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: _record_type_validation done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: channel_number: 391 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string running... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string type: 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_aux_set_string running done: ret = 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: median_before: 260.557264 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: read_number: 2287 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: start_mux: 2 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: checked_aux: start_time: 36886851 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: aux stuff done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_write() ret: 76457 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: slow5_rec_free() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record: function complete, returning 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: -1 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next reached end of file (EOF)(-1): -1: ['SLOW5_ERR_EOF', 'End Of File reached'] 110s 14-Nov-24 16:13:27 - [DEBUG]: examples/example2.slow5 closed 110s 14-Nov-24 16:13:27 - [DEBUG]: examples/example_write_append_aux.blow5 closed 110s 14-Nov-24 16:13:27 - [DEBUG]: FILE: examples/example2.slow5, mode: r 110s 14-Nov-24 16:13:27 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r' 110s 14-Nov-24 16:13:27 - [DEBUG]: Number of read_groups: 4 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next_multi return: 3 110s 14-Nov-24 16:13:27 - [DEBUG]: get_aux_names starting 110s 14-Nov-24 16:13:27 - [DEBUG]: get_aux_names aux_len: 5 110s 14-Nov-24 16:13:27 - [DEBUG]: get_aux_types starting 110s 14-Nov-24 16:13:27 - [DEBUG]: get_aux_types aux_len: 5 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next_multi return: 3 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next_multi return: 2 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next_multi has no more batches - batchsize:3 ret:2 110s 14-Nov-24 16:13:27 - [DEBUG]: seq_reads_multi timings: 110s 14-Nov-24 16:13:27 - [DEBUG]: aux_total_time: 0.0002200603485107422 110s 14-Nov-24 16:13:27 - [DEBUG]: primary_total_time: 0.0002465248107910156 110s 14-Nov-24 16:13:27 - [DEBUG]: pA_total_time: 0.001386404037475586 110s 14-Nov-24 16:13:27 - [DEBUG]: signal_total_time: 0.00022792816162109375 110s 14-Nov-24 16:13:27 - [DEBUG]: examples/example2.slow5 closed 110s 14-Nov-24 16:13:27 - [DEBUG]: FILE: examples/example2.slow5, mode: r 110s 14-Nov-24 16:13:27 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r' 110s 14-Nov-24 16:13:27 - [DEBUG]: Number of read_groups: 4 110s 14-Nov-24 16:13:27 - [DEBUG]: pathname: examples/example2.slow5 110s 14-Nov-24 16:13:27 - [DEBUG]: total_time_slow5_get_next: 0.012377738952636719 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_time_yield_reads: 0.0018839836120605469 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_single_write_time: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_multi_write_time: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: FILE: examples/example2.slow5, mode: r 110s 14-Nov-24 16:13:27 - [DEBUG]: Creating/loading index... 110s 14-Nov-24 16:13:27 - [DEBUG]: Setting up batching... 110s 14-Nov-24 16:13:27 - [DEBUG]: read_list: ['r0', 'r1', 'r2', 'r3', 'r4', 'r5', '0a238451-b9ed-446d-a152-badd074006c4', '0d624d4b-671f-40b8-9798-84f2ccc4d7fc'] 110s 14-Nov-24 16:13:27 - [DEBUG]: batch for loop start 110s 14-Nov-24 16:13:27 - [DEBUG]: Batch: r0,r1,r2 110s 14-Nov-24 16:13:27 - [DEBUG]: Starting rid assignment 110s 14-Nov-24 16:13:27 - [DEBUG]: readID: r0, bin: b'r0' 110s 14-Nov-24 16:13:27 - [DEBUG]: readID: r1, bin: b'r1' 110s 14-Nov-24 16:13:27 - [DEBUG]: readID: r2, bin: b'r2' 110s 14-Nov-24 16:13:27 - [DEBUG]: rid assignment complete 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_batch: num_reads: 3 110s 14-Nov-24 16:13:27 - [DEBUG]: get_read_multi slow5_get_batch ret: 3 110s 14-Nov-24 16:13:27 - [DEBUG]: get_aux_names starting 110s 14-Nov-24 16:13:27 - [DEBUG]: get_aux_names aux_len: 5 110s 14-Nov-24 16:13:27 - [DEBUG]: get_aux_types starting 110s 14-Nov-24 16:13:27 - [DEBUG]: get_aux_types aux_len: 5 110s 14-Nov-24 16:13:27 - [DEBUG]: Batch: r3,r4,r5 110s 14-Nov-24 16:13:27 - [DEBUG]: Starting rid assignment 110s 14-Nov-24 16:13:27 - [DEBUG]: readID: r3, bin: b'r3' 110s 14-Nov-24 16:13:27 - [DEBUG]: readID: r4, bin: b'r4' 110s 14-Nov-24 16:13:27 - [DEBUG]: readID: r5, bin: b'r5' 110s 14-Nov-24 16:13:27 - [DEBUG]: rid assignment complete 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_batch: num_reads: 3 110s 14-Nov-24 16:13:27 - [DEBUG]: get_read_multi slow5_get_batch ret: 3 110s 14-Nov-24 16:13:27 - [DEBUG]: Batch: 0a238451-b9ed-446d-a152-badd074006c4,0d624d4b-671f-40b8-9798-84f2ccc4d7fc 110s 14-Nov-24 16:13:27 - [DEBUG]: Starting rid assignment 110s 14-Nov-24 16:13:27 - [DEBUG]: readID: 0a238451-b9ed-446d-a152-badd074006c4, bin: b'0a238451-b9ed-446d-a152-badd074006c4' 110s 14-Nov-24 16:13:27 - [DEBUG]: readID: 0d624d4b-671f-40b8-9798-84f2ccc4d7fc, bin: b'0d624d4b-671f-40b8-9798-84f2ccc4d7fc' 110s 14-Nov-24 16:13:27 - [DEBUG]: rid assignment complete 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_batch: num_reads: 2 110s 14-Nov-24 16:13:27 - [DEBUG]: get_read_multi slow5_get_batch ret: 2 110s 14-Nov-24 16:13:27 - [DEBUG]: seq_reads_multi timings: 110s 14-Nov-24 16:13:27 - [DEBUG]: examples/example2.slow5 closed 110s 14-Nov-24 16:13:27 - [DEBUG]: FILE: examples/example_write_aux_multi.slow5, mode: w 110s 14-Nov-24 16:13:27 - [DEBUG]: FILE: b'examples/example_write_aux_multi.slow5', mode: b'w' 110s 14-Nov-24 16:13:27 - [DEBUG]: Not writing blow5, skipping compression steps 110s 14-Nov-24 16:13:27 - [DEBUG]: examples/example_write_append_aux.blow5 already closed 110s 14-Nov-24 16:13:27 - [DEBUG]: pathname: examples/example_write_append_aux.blow5 110s 14-Nov-24 16:13:27 - [DEBUG]: total_time_slow5_get_next: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_time_yield_reads: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_single_write_time: 0.027630090713500977 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_multi_write_time: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: FILE: examples/example2.slow5, mode: r 110s 14-Nov-24 16:13:27 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r' 110s 14-Nov-24 16:13:27 - [DEBUG]: Number of read_groups: 4 110s 14-Nov-24 16:13:27 - [DEBUG]: pathname: examples/example2.slow5 110s 14-Nov-24 16:13:27 - [DEBUG]: total_time_slow5_get_next: 0.017242431640625 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_time_yield_reads: 0.01874685287475586 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_single_write_time: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_multi_write_time: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: get_aux_names starting 110s 14-Nov-24 16:13:27 - [DEBUG]: get_aux_names aux_len: 5 110s 14-Nov-24 16:13:27 - [DEBUG]: get_aux_types starting 110s 14-Nov-24 16:13:27 - [DEBUG]: get_aux_types aux_len: 5 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: 0 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next return: -1 110s 14-Nov-24 16:13:27 - [DEBUG]: slow5_get_next reached end of file (EOF)(-1): -1: ['SLOW5_ERR_EOF', 'End Of File reached'] 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: Setting up batching... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: batch for loop start 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: _record_type_validation running 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux stuff done 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux stuff done 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux stuff done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: _record_type_validation done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: checking header stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: writting header... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: header written 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: checked_aux: channel_number: 281 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: slow5_aux_set_string running... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: slow5_aux_set_string type: 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: slow5_aux_set_string running done: ret = 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: checked_aux: median_before: 231.363533 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: checked_aux: read_number: 4019 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: checked_aux: start_mux: 1 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: checked_aux: start_time: 78470500 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: aux stuff done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: checked_aux: channel_number: 391 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: slow5_aux_set_string running... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: slow5_aux_set_string type: 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: slow5_aux_set_string running done: ret = 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: checked_aux: median_before: 260.557264 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: checked_aux: read_number: 2287 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: checked_aux: start_mux: 2 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: checked_aux: start_time: 36886851 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: aux stuff done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: checked_aux: channel_number: 281 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: slow5_aux_set_string running... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: slow5_aux_set_string type: 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: slow5_aux_set_string running done: ret = 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: checked_aux: median_before: 231.363533 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: checked_aux: read_number: 4019 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: checked_aux: start_mux: 1 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: checked_aux: start_time: 78470500 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: aux stuff done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: slow5_write_batch() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: free() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: free() aux 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: _record_type_validation running 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux stuff done 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux stuff done 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux stuff done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: _record_type_validation done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: checked_aux: channel_number: 391 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: slow5_aux_set_string running... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: slow5_aux_set_string type: 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: slow5_aux_set_string running done: ret = 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: checked_aux: median_before: 260.557264 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: checked_aux: read_number: 2287 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: checked_aux: start_mux: 2 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: checked_aux: start_time: 36886851 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: aux stuff done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: checked_aux: channel_number: 281 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: slow5_aux_set_string running... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: slow5_aux_set_string type: 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: slow5_aux_set_string running done: ret = 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: checked_aux: median_before: 231.363533 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: checked_aux: read_number: 4019 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: checked_aux: start_mux: 1 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: checked_aux: start_time: 78470500 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: aux stuff done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: checked_aux: channel_number: 391 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: slow5_aux_set_string running... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: slow5_aux_set_string type: 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: slow5_aux_set_string running done: ret = 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: checked_aux: median_before: 260.557264 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: checked_aux: read_number: 2287 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: checked_aux: start_mux: 2 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: checked_aux: start_time: 36886851 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: aux stuff done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: slow5_write_batch() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: free() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: free() aux 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: _record_type_validation running 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux stuff done 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: doing aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux passed tests... 110s 14-Nov-24 16:13:27 - [DEBUG]: _record_type_validation: aux stuff done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: _record_type_validation done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: checked_aux: channel_number: 281 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: slow5_aux_set_string running... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: slow5_aux_set_string type: 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: slow5_aux_set_string running done: ret = 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: checked_aux: median_before: 231.363533 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: checked_aux: read_number: 4019 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: checked_aux: start_mux: 1 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: checked_aux: start_time: 78470500 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: aux stuff done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: slow5_rec_init() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: self.write assignments... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: self.write.raw_signal malloc... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: self.write.raw_signal malloc done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: self.write assignments done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: self.write processing raw_signal 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: self.write raw_signal done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: aux stuff... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: checked_aux: channel_number: 391 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: slow5_aux_set_string running... 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: slow5_aux_set_string type: 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: slow5_aux_set_string running done: ret = 0 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: checked_aux: median_before: 260.557264 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: checked_aux: read_number: 2287 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: checked_aux: start_mux: 2 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: checked_aux: start_time: 36886851 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: aux stuff done 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: slow5_write_batch() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: free() 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: free() aux 110s 14-Nov-24 16:13:27 - [DEBUG]: write_record_batch: function complete, returning 0 110s 14-Nov-24 16:13:27 - [DEBUG]: examples/example2.slow5 closed 110s 14-Nov-24 16:13:27 - [DEBUG]: examples/example_write_aux_multi.slow5 closed 110s 14-Nov-24 16:13:27 - [DEBUG]: FILE: examples/example2.slow5, mode: r 110s 14-Nov-24 16:13:27 - [DEBUG]: FILE: b'examples/example2.slow5', mode: b'r' 110s 14-Nov-24 16:13:27 - [DEBUG]: Number of read_groups: 4 110s 14-Nov-24 16:13:27 - [DEBUG]: pathname: examples/example2.slow5 110s 14-Nov-24 16:13:27 - [DEBUG]: total_time_slow5_get_next: 0.017377614974975586 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_time_yield_reads: 0.018985509872436523 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_single_write_time: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_multi_write_time: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: FILE: examples/example2.slow5, mode: r 110s 110s ret: write_record(): 0 110s ret: write_record(): 0 110s ret: write_record(): 0 110s ret: write_record(): 0 110s ret: write_record(): 0 110s ret: write_record(): 0 110s ret: write_record(): 0 110s ret: write_record(): 0 110s ============================================== 110s write reads with aux 110s ret: write_header(): 0 110s ret: write_header(): 0 110s ret: write_record(): 0 110s ret: write_record(): 0 110s ret: write_record(): 0 110s ret: write_record(): 0 110s ret: write_record(): 0 110s ret: write_record(): 0 110s ret: write_record(): 0 110s ret: write_record(): 0 110s ============================================== 110s append reads with aux 110s ret: write_header(): 0 110s ret: write_header(): 0 110s ret: write_record(): 0 110s ret: write_record(): 0 110s ret: write_record(): 0 110s ret: write_record(): 0 110s ret: write_record(): 0 110s ret: write_record(): 0 110s ret: write_record(): 0 110s ret: write_record(): 0 110s ret: write_record(): 0 110s ret: write_record(): 0 110s ret: write_record(): 0 110s ret: write_record(): 0 110s ret: write_record(): 0 110s ret: write_record(): 0 110s ret: write_record(): 0 110s ret: write_record(): 0 110s ============================================== 110s seq_reads_multi with aux: 110s type check reads: 110s r0 110s read_number 4019 110s r1 110s read_number 2287 110s r2 110s read_number 4019 110s r3 110s read_number 2287 110s r4 110s read_number 4019 110s r5 110s read_number 2287 110s 0a238451-b9ed-446d-a152-badd074006c4 110s read_number 4019 110s 0d624d4b-671f-40b8-9798-84f2ccc4d7fc 110s read_number 2287 110s ============================================== 110s get_reads_multi with aux: 110s type check reads: 110s r0 110s read_number 4019 110s r1 110s read_number 2287 110s r2 110s read_number 4019 110s r3 110s read_number 2287 110s r4 110s read_number 4019 110s r5 110s read_number 2287 110s 0a238451-b9ed-446d-a152-badd074006c4 110s read_number 4019 110s 0d624d4b-671f-40b8-9798-84f2ccc4d7fc 110s read_number 2287 110s ============================================== 110s write reads with aux multi 110s ret: write_header(): 0 110s ret: write_header(): 0 110s {'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)}} 110s {'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}} 110s ret: write_record(): 0 110s ============================================== 110s get all readIDs from index 110s ['r0', 'r1', 'r2', 'r3', 'r4', 'r5', '0a238451-b9ed-446d-a152-badd074006c4', '0d624d4b-671f-40b8-9798-84f2ccc4d7fc'] 110s number of reads: 8 110s ============================================== 110s done 110s 14-Nov-24 16:13:27 - [DEBUG]: Creating/loading index... 110s 14-Nov-24 16:13:27 - [DEBUG]: examples/example2.slow5 closed 110s 14-Nov-24 16:13:27 - [DEBUG]: pathname: examples/example.slow5 110s 14-Nov-24 16:13:27 - [DEBUG]: total_time_slow5_get_next: 0.01146078109741211 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_time_yield_reads: 0.012264251708984375 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_single_write_time: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_multi_write_time: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: pathname: examples/example2.slow5 110s 14-Nov-24 16:13:27 - [DEBUG]: total_time_slow5_get_next: 0.01693892478942871 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_time_yield_reads: 0.020511150360107422 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_single_write_time: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_multi_write_time: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: examples/example_write_aux_multi.slow5 already closed 110s 14-Nov-24 16:13:27 - [DEBUG]: pathname: examples/example_write_aux_multi.slow5 110s 14-Nov-24 16:13:27 - [DEBUG]: total_time_slow5_get_next: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_time_yield_reads: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_single_write_time: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_multi_write_signal_time: 0.031023502349853516 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_multi_write_time: 0.05960273742675781 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: pathname: examples/example2.slow5 110s 14-Nov-24 16:13:27 - [DEBUG]: total_time_slow5_get_next: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_time_yield_reads: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_single_write_time: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_multi_write_time: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: examples/example_write_append_aux.blow5 already closed 110s 14-Nov-24 16:13:27 - [DEBUG]: pathname: examples/example_write_append_aux.blow5 110s 14-Nov-24 16:13:27 - [DEBUG]: total_time_slow5_get_next: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_time_yield_reads: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_single_write_time: 0.027704715728759766 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_multi_write_time: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: pathname: examples/example2.slow5 110s 14-Nov-24 16:13:27 - [DEBUG]: total_time_slow5_get_next: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_time_yield_reads: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_single_write_time: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_multi_write_signal_time: 0.0 seconds 110s 14-Nov-24 16:13:27 - [DEBUG]: total_multi_write_time: 0.0 seconds 111s autopkgtest [16:13:28]: test run-pybinding-test: -----------------------] 112s autopkgtest [16:13:29]: test run-pybinding-test: - - - - - - - - - - results - - - - - - - - - - 112s run-pybinding-test PASS 112s autopkgtest [16:13:29]: test run-pkg-test: preparing testbed 202s autopkgtest [16:14:59]: testbed dpkg architecture: arm64 202s autopkgtest [16:14:59]: testbed apt version: 2.9.8 202s autopkgtest [16:14:59]: @@@@@@@@@@@@@@@@@@@@ test bed setup 203s Get:1 http://ftpmaster.internal/ubuntu plucky-proposed InRelease [73.9 kB] 203s Get:2 http://ftpmaster.internal/ubuntu plucky-proposed/main Sources [105 kB] 203s Get:3 http://ftpmaster.internal/ubuntu plucky-proposed/restricted Sources [7016 B] 203s Get:4 http://ftpmaster.internal/ubuntu plucky-proposed/multiverse Sources [15.3 kB] 203s Get:5 http://ftpmaster.internal/ubuntu plucky-proposed/universe Sources [966 kB] 203s Get:6 http://ftpmaster.internal/ubuntu plucky-proposed/main arm64 Packages [138 kB] 203s Get:7 http://ftpmaster.internal/ubuntu plucky-proposed/restricted arm64 Packages [50.3 kB] 203s Get:8 http://ftpmaster.internal/ubuntu plucky-proposed/universe arm64 Packages [724 kB] 203s Get:9 http://ftpmaster.internal/ubuntu plucky-proposed/multiverse arm64 Packages [6012 B] 203s Fetched 2085 kB in 1s (2396 kB/s) 203s Reading package lists... 206s Reading package lists... 206s Building dependency tree... 206s Reading state information... 207s Calculating upgrade... 207s The following packages will be upgraded: 207s pastebinit python3-systemd 207s 2 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 207s Need to get 61.6 kB of archives. 207s After this operation, 347 kB of additional disk space will be used. 207s Get:1 http://ftpmaster.internal/ubuntu plucky/main arm64 pastebinit all 1.7.1-1 [14.9 kB] 208s Get:2 http://ftpmaster.internal/ubuntu plucky/main arm64 python3-systemd arm64 235-1build5 [46.7 kB] 208s Fetched 61.6 kB in 0s (168 kB/s) 209s (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 ... 79925 files and directories currently installed.) 209s Preparing to unpack .../pastebinit_1.7.1-1_all.deb ... 209s Unpacking pastebinit (1.7.1-1) over (1.7.0-1) ... 209s Preparing to unpack .../python3-systemd_235-1build5_arm64.deb ... 209s Unpacking python3-systemd (235-1build5) over (235-1build4) ... 209s Setting up pastebinit (1.7.1-1) ... 209s Setting up python3-systemd (235-1build5) ... 209s Processing triggers for man-db (2.12.1-3) ... 210s Reading package lists... 210s Building dependency tree... 210s Reading state information... 211s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 211s Hit:1 http://ftpmaster.internal/ubuntu plucky-proposed InRelease 211s Hit:2 http://ftpmaster.internal/ubuntu plucky InRelease 211s Hit:3 http://ftpmaster.internal/ubuntu plucky-updates InRelease 211s Hit:4 http://ftpmaster.internal/ubuntu plucky-security InRelease 213s Reading package lists... 213s Reading package lists... 213s Building dependency tree... 213s Reading state information... 214s Calculating upgrade... 214s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 214s Reading package lists... 214s Building dependency tree... 214s Reading state information... 215s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 219s Reading package lists... 219s Building dependency tree... 219s Reading state information... 220s Starting pkgProblemResolver with broken count: 0 220s Starting 2 pkgProblemResolver with broken count: 0 220s Done 221s The following additional packages will be installed: 221s build-essential cpp cpp-14 cpp-14-aarch64-linux-gnu cpp-aarch64-linux-gnu 221s g++ g++-14 g++-14-aarch64-linux-gnu g++-aarch64-linux-gnu gcc gcc-14 221s gcc-14-aarch64-linux-gnu gcc-aarch64-linux-gnu libasan8 libblas3 libcc1-0 221s libgcc-14-dev libgfortran5 libgomp1 libhwasan0 libisl23 libitm1 liblapack3 221s liblsan0 libmpc3 libslow5-0t64 libslow5-dev libstdc++-14-dev 221s libstreamvbyte-dev libstreamvbyte0 libtsan2 libubsan1 python3-numpy 221s python3-slow5 zlib1g-dev 221s Suggested packages: 221s cpp-doc gcc-14-locales cpp-14-doc gcc-14-doc gcc-multilib manpages-dev 221s autoconf automake libtool flex bison gdb gcc-doc gdb-aarch64-linux-gnu 221s libstdc++-14-doc gfortran python-numpy-doc python3-dev python3-pytest 221s The following NEW packages will be installed: 221s autopkgtest-satdep build-essential cpp cpp-14 cpp-14-aarch64-linux-gnu 221s cpp-aarch64-linux-gnu g++ g++-14 g++-14-aarch64-linux-gnu 221s g++-aarch64-linux-gnu gcc gcc-14 gcc-14-aarch64-linux-gnu 221s gcc-aarch64-linux-gnu libasan8 libblas3 libcc1-0 libgcc-14-dev libgfortran5 221s libgomp1 libhwasan0 libisl23 libitm1 liblapack3 liblsan0 libmpc3 221s libslow5-0t64 libslow5-dev libstdc++-14-dev libstreamvbyte-dev 221s libstreamvbyte0 libtsan2 libubsan1 python3-numpy python3-slow5 zlib1g-dev 221s 0 upgraded, 36 newly installed, 0 to remove and 0 not upgraded. 221s Need to get 68.4 MB/68.4 MB of archives. 221s After this operation, 251 MB of additional disk space will be used. 221s Get:1 /tmp/autopkgtest.AGrcur/2-autopkgtest-satdep.deb autopkgtest-satdep arm64 0 [760 B] 221s Get:2 http://ftpmaster.internal/ubuntu plucky/main arm64 libisl23 arm64 0.27-1 [676 kB] 221s Get:3 http://ftpmaster.internal/ubuntu plucky/main arm64 libmpc3 arm64 1.3.1-1build2 [56.8 kB] 221s Get:4 http://ftpmaster.internal/ubuntu plucky/main arm64 cpp-14-aarch64-linux-gnu arm64 14.2.0-8ubuntu1 [10.6 MB] 222s Get:5 http://ftpmaster.internal/ubuntu plucky/main arm64 cpp-14 arm64 14.2.0-8ubuntu1 [1028 B] 222s Get:6 http://ftpmaster.internal/ubuntu plucky/main arm64 cpp-aarch64-linux-gnu arm64 4:14.1.0-2ubuntu1 [5452 B] 222s Get:7 http://ftpmaster.internal/ubuntu plucky/main arm64 cpp arm64 4:14.1.0-2ubuntu1 [22.5 kB] 222s Get:8 http://ftpmaster.internal/ubuntu plucky/main arm64 libcc1-0 arm64 14.2.0-8ubuntu1 [49.7 kB] 222s Get:9 http://ftpmaster.internal/ubuntu plucky/main arm64 libgomp1 arm64 14.2.0-8ubuntu1 [145 kB] 222s Get:10 http://ftpmaster.internal/ubuntu plucky/main arm64 libitm1 arm64 14.2.0-8ubuntu1 [27.8 kB] 222s Get:11 http://ftpmaster.internal/ubuntu plucky/main arm64 libasan8 arm64 14.2.0-8ubuntu1 [2893 kB] 222s Get:12 http://ftpmaster.internal/ubuntu plucky/main arm64 liblsan0 arm64 14.2.0-8ubuntu1 [1283 kB] 222s Get:13 http://ftpmaster.internal/ubuntu plucky/main arm64 libtsan2 arm64 14.2.0-8ubuntu1 [2686 kB] 222s Get:14 http://ftpmaster.internal/ubuntu plucky/main arm64 libubsan1 arm64 14.2.0-8ubuntu1 [1151 kB] 222s Get:15 http://ftpmaster.internal/ubuntu plucky/main arm64 libhwasan0 arm64 14.2.0-8ubuntu1 [1598 kB] 222s Get:16 http://ftpmaster.internal/ubuntu plucky/main arm64 libgcc-14-dev arm64 14.2.0-8ubuntu1 [2594 kB] 223s Get:17 http://ftpmaster.internal/ubuntu plucky/main arm64 gcc-14-aarch64-linux-gnu arm64 14.2.0-8ubuntu1 [20.9 MB] 225s Get:18 http://ftpmaster.internal/ubuntu plucky/main arm64 gcc-14 arm64 14.2.0-8ubuntu1 [518 kB] 225s Get:19 http://ftpmaster.internal/ubuntu plucky/main arm64 gcc-aarch64-linux-gnu arm64 4:14.1.0-2ubuntu1 [1200 B] 225s Get:20 http://ftpmaster.internal/ubuntu plucky/main arm64 gcc arm64 4:14.1.0-2ubuntu1 [4994 B] 225s Get:21 http://ftpmaster.internal/ubuntu plucky/main arm64 libstdc++-14-dev arm64 14.2.0-8ubuntu1 [2476 kB] 225s Get:22 http://ftpmaster.internal/ubuntu plucky/main arm64 g++-14-aarch64-linux-gnu arm64 14.2.0-8ubuntu1 [12.1 MB] 226s Get:23 http://ftpmaster.internal/ubuntu plucky/main arm64 g++-14 arm64 14.2.0-8ubuntu1 [19.9 kB] 226s Get:24 http://ftpmaster.internal/ubuntu plucky/main arm64 g++-aarch64-linux-gnu arm64 4:14.1.0-2ubuntu1 [958 B] 226s Get:25 http://ftpmaster.internal/ubuntu plucky/main arm64 g++ arm64 4:14.1.0-2ubuntu1 [1080 B] 226s Get:26 http://ftpmaster.internal/ubuntu plucky/main arm64 build-essential arm64 12.10ubuntu1 [4932 B] 226s Get:27 http://ftpmaster.internal/ubuntu plucky/main arm64 libblas3 arm64 3.12.0-3build2 [152 kB] 226s Get:28 http://ftpmaster.internal/ubuntu plucky/main arm64 libgfortran5 arm64 14.2.0-8ubuntu1 [438 kB] 226s Get:29 http://ftpmaster.internal/ubuntu plucky/main arm64 liblapack3 arm64 3.12.0-3build2 [2293 kB] 226s Get:30 http://ftpmaster.internal/ubuntu plucky/universe arm64 libslow5-0t64 arm64 0.7.0+dfsg-3 [61.9 kB] 226s Get:31 http://ftpmaster.internal/ubuntu plucky/universe arm64 libslow5-dev arm64 0.7.0+dfsg-3 [90.4 kB] 226s Get:32 http://ftpmaster.internal/ubuntu plucky/universe arm64 libstreamvbyte0 arm64 0.4.1-4ubuntu1 [6260 B] 226s Get:33 http://ftpmaster.internal/ubuntu plucky/universe arm64 libstreamvbyte-dev arm64 0.4.1-4ubuntu1 [6620 B] 226s Get:34 http://ftpmaster.internal/ubuntu plucky-proposed/main arm64 python3-numpy arm64 1:1.26.4+ds-11ubuntu1 [4149 kB] 226s Get:35 http://ftpmaster.internal/ubuntu plucky/universe arm64 python3-slow5 arm64 0.7.0+dfsg-3 [452 kB] 227s Get:36 http://ftpmaster.internal/ubuntu plucky/main arm64 zlib1g-dev arm64 1:1.3.dfsg+really1.3.1-1ubuntu1 [894 kB] 227s Fetched 68.4 MB in 6s (11.9 MB/s) 227s Selecting previously unselected package libisl23:arm64. 227s (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 ... 79930 files and directories currently installed.) 227s Preparing to unpack .../00-libisl23_0.27-1_arm64.deb ... 227s Unpacking libisl23:arm64 (0.27-1) ... 227s Selecting previously unselected package libmpc3:arm64. 227s Preparing to unpack .../01-libmpc3_1.3.1-1build2_arm64.deb ... 227s Unpacking libmpc3:arm64 (1.3.1-1build2) ... 227s Selecting previously unselected package cpp-14-aarch64-linux-gnu. 227s Preparing to unpack .../02-cpp-14-aarch64-linux-gnu_14.2.0-8ubuntu1_arm64.deb ... 227s Unpacking cpp-14-aarch64-linux-gnu (14.2.0-8ubuntu1) ... 227s Selecting previously unselected package cpp-14. 227s Preparing to unpack .../03-cpp-14_14.2.0-8ubuntu1_arm64.deb ... 227s Unpacking cpp-14 (14.2.0-8ubuntu1) ... 227s Selecting previously unselected package cpp-aarch64-linux-gnu. 227s Preparing to unpack .../04-cpp-aarch64-linux-gnu_4%3a14.1.0-2ubuntu1_arm64.deb ... 227s Unpacking cpp-aarch64-linux-gnu (4:14.1.0-2ubuntu1) ... 228s Selecting previously unselected package cpp. 228s Preparing to unpack .../05-cpp_4%3a14.1.0-2ubuntu1_arm64.deb ... 228s Unpacking cpp (4:14.1.0-2ubuntu1) ... 228s Selecting previously unselected package libcc1-0:arm64. 228s Preparing to unpack .../06-libcc1-0_14.2.0-8ubuntu1_arm64.deb ... 228s Unpacking libcc1-0:arm64 (14.2.0-8ubuntu1) ... 228s Selecting previously unselected package libgomp1:arm64. 228s Preparing to unpack .../07-libgomp1_14.2.0-8ubuntu1_arm64.deb ... 228s Unpacking libgomp1:arm64 (14.2.0-8ubuntu1) ... 228s Selecting previously unselected package libitm1:arm64. 228s Preparing to unpack .../08-libitm1_14.2.0-8ubuntu1_arm64.deb ... 228s Unpacking libitm1:arm64 (14.2.0-8ubuntu1) ... 228s Selecting previously unselected package libasan8:arm64. 228s Preparing to unpack .../09-libasan8_14.2.0-8ubuntu1_arm64.deb ... 228s Unpacking libasan8:arm64 (14.2.0-8ubuntu1) ... 228s Selecting previously unselected package liblsan0:arm64. 228s Preparing to unpack .../10-liblsan0_14.2.0-8ubuntu1_arm64.deb ... 228s Unpacking liblsan0:arm64 (14.2.0-8ubuntu1) ... 228s Selecting previously unselected package libtsan2:arm64. 228s Preparing to unpack .../11-libtsan2_14.2.0-8ubuntu1_arm64.deb ... 228s Unpacking libtsan2:arm64 (14.2.0-8ubuntu1) ... 228s Selecting previously unselected package libubsan1:arm64. 228s Preparing to unpack .../12-libubsan1_14.2.0-8ubuntu1_arm64.deb ... 228s Unpacking libubsan1:arm64 (14.2.0-8ubuntu1) ... 228s Selecting previously unselected package libhwasan0:arm64. 228s Preparing to unpack .../13-libhwasan0_14.2.0-8ubuntu1_arm64.deb ... 228s Unpacking libhwasan0:arm64 (14.2.0-8ubuntu1) ... 228s Selecting previously unselected package libgcc-14-dev:arm64. 228s Preparing to unpack .../14-libgcc-14-dev_14.2.0-8ubuntu1_arm64.deb ... 228s Unpacking libgcc-14-dev:arm64 (14.2.0-8ubuntu1) ... 228s Selecting previously unselected package gcc-14-aarch64-linux-gnu. 228s Preparing to unpack .../15-gcc-14-aarch64-linux-gnu_14.2.0-8ubuntu1_arm64.deb ... 228s Unpacking gcc-14-aarch64-linux-gnu (14.2.0-8ubuntu1) ... 229s Selecting previously unselected package gcc-14. 229s Preparing to unpack .../16-gcc-14_14.2.0-8ubuntu1_arm64.deb ... 229s Unpacking gcc-14 (14.2.0-8ubuntu1) ... 229s Selecting previously unselected package gcc-aarch64-linux-gnu. 229s Preparing to unpack .../17-gcc-aarch64-linux-gnu_4%3a14.1.0-2ubuntu1_arm64.deb ... 229s Unpacking gcc-aarch64-linux-gnu (4:14.1.0-2ubuntu1) ... 229s Selecting previously unselected package gcc. 229s Preparing to unpack .../18-gcc_4%3a14.1.0-2ubuntu1_arm64.deb ... 229s Unpacking gcc (4:14.1.0-2ubuntu1) ... 229s Selecting previously unselected package libstdc++-14-dev:arm64. 229s Preparing to unpack .../19-libstdc++-14-dev_14.2.0-8ubuntu1_arm64.deb ... 229s Unpacking libstdc++-14-dev:arm64 (14.2.0-8ubuntu1) ... 229s Selecting previously unselected package g++-14-aarch64-linux-gnu. 229s Preparing to unpack .../20-g++-14-aarch64-linux-gnu_14.2.0-8ubuntu1_arm64.deb ... 229s Unpacking g++-14-aarch64-linux-gnu (14.2.0-8ubuntu1) ... 229s Selecting previously unselected package g++-14. 229s Preparing to unpack .../21-g++-14_14.2.0-8ubuntu1_arm64.deb ... 229s Unpacking g++-14 (14.2.0-8ubuntu1) ... 229s Selecting previously unselected package g++-aarch64-linux-gnu. 229s Preparing to unpack .../22-g++-aarch64-linux-gnu_4%3a14.1.0-2ubuntu1_arm64.deb ... 229s Unpacking g++-aarch64-linux-gnu (4:14.1.0-2ubuntu1) ... 229s Selecting previously unselected package g++. 229s Preparing to unpack .../23-g++_4%3a14.1.0-2ubuntu1_arm64.deb ... 229s Unpacking g++ (4:14.1.0-2ubuntu1) ... 229s Selecting previously unselected package build-essential. 229s Preparing to unpack .../24-build-essential_12.10ubuntu1_arm64.deb ... 229s Unpacking build-essential (12.10ubuntu1) ... 229s Selecting previously unselected package libblas3:arm64. 229s Preparing to unpack .../25-libblas3_3.12.0-3build2_arm64.deb ... 229s Unpacking libblas3:arm64 (3.12.0-3build2) ... 229s Selecting previously unselected package libgfortran5:arm64. 229s Preparing to unpack .../26-libgfortran5_14.2.0-8ubuntu1_arm64.deb ... 229s Unpacking libgfortran5:arm64 (14.2.0-8ubuntu1) ... 230s Selecting previously unselected package liblapack3:arm64. 230s Preparing to unpack .../27-liblapack3_3.12.0-3build2_arm64.deb ... 230s Unpacking liblapack3:arm64 (3.12.0-3build2) ... 230s Selecting previously unselected package libslow5-0t64:arm64. 230s Preparing to unpack .../28-libslow5-0t64_0.7.0+dfsg-3_arm64.deb ... 230s Unpacking libslow5-0t64:arm64 (0.7.0+dfsg-3) ... 230s Selecting previously unselected package libslow5-dev:arm64. 230s Preparing to unpack .../29-libslow5-dev_0.7.0+dfsg-3_arm64.deb ... 230s Unpacking libslow5-dev:arm64 (0.7.0+dfsg-3) ... 230s Selecting previously unselected package libstreamvbyte0:arm64. 230s Preparing to unpack .../30-libstreamvbyte0_0.4.1-4ubuntu1_arm64.deb ... 230s Unpacking libstreamvbyte0:arm64 (0.4.1-4ubuntu1) ... 230s Selecting previously unselected package libstreamvbyte-dev:arm64. 230s Preparing to unpack .../31-libstreamvbyte-dev_0.4.1-4ubuntu1_arm64.deb ... 230s Unpacking libstreamvbyte-dev:arm64 (0.4.1-4ubuntu1) ... 230s Selecting previously unselected package python3-numpy. 230s Preparing to unpack .../32-python3-numpy_1%3a1.26.4+ds-11ubuntu1_arm64.deb ... 230s Unpacking python3-numpy (1:1.26.4+ds-11ubuntu1) ... 230s Selecting previously unselected package python3-slow5. 230s Preparing to unpack .../33-python3-slow5_0.7.0+dfsg-3_arm64.deb ... 230s Unpacking python3-slow5 (0.7.0+dfsg-3) ... 230s Selecting previously unselected package zlib1g-dev:arm64. 230s Preparing to unpack .../34-zlib1g-dev_1%3a1.3.dfsg+really1.3.1-1ubuntu1_arm64.deb ... 230s Unpacking zlib1g-dev:arm64 (1:1.3.dfsg+really1.3.1-1ubuntu1) ... 230s Selecting previously unselected package autopkgtest-satdep. 230s Preparing to unpack .../35-2-autopkgtest-satdep.deb ... 230s Unpacking autopkgtest-satdep (0) ... 230s Setting up libstreamvbyte0:arm64 (0.4.1-4ubuntu1) ... 230s Setting up libgomp1:arm64 (14.2.0-8ubuntu1) ... 230s Setting up libblas3:arm64 (3.12.0-3build2) ... 230s update-alternatives: using /usr/lib/aarch64-linux-gnu/blas/libblas.so.3 to provide /usr/lib/aarch64-linux-gnu/libblas.so.3 (libblas.so.3-aarch64-linux-gnu) in auto mode 230s Setting up libstreamvbyte-dev:arm64 (0.4.1-4ubuntu1) ... 230s Setting up libmpc3:arm64 (1.3.1-1build2) ... 230s Setting up libslow5-0t64:arm64 (0.7.0+dfsg-3) ... 230s Setting up libgfortran5:arm64 (14.2.0-8ubuntu1) ... 230s Setting up libubsan1:arm64 (14.2.0-8ubuntu1) ... 230s Setting up zlib1g-dev:arm64 (1:1.3.dfsg+really1.3.1-1ubuntu1) ... 230s Setting up libhwasan0:arm64 (14.2.0-8ubuntu1) ... 230s Setting up libasan8:arm64 (14.2.0-8ubuntu1) ... 230s Setting up libtsan2:arm64 (14.2.0-8ubuntu1) ... 230s Setting up libisl23:arm64 (0.27-1) ... 230s Setting up libcc1-0:arm64 (14.2.0-8ubuntu1) ... 230s Setting up liblsan0:arm64 (14.2.0-8ubuntu1) ... 230s Setting up libitm1:arm64 (14.2.0-8ubuntu1) ... 230s Setting up liblapack3:arm64 (3.12.0-3build2) ... 230s update-alternatives: using /usr/lib/aarch64-linux-gnu/lapack/liblapack.so.3 to provide /usr/lib/aarch64-linux-gnu/liblapack.so.3 (liblapack.so.3-aarch64-linux-gnu) in auto mode 230s Setting up libslow5-dev:arm64 (0.7.0+dfsg-3) ... 230s Setting up python3-numpy (1:1.26.4+ds-11ubuntu1) ... 233s Setting up cpp-14-aarch64-linux-gnu (14.2.0-8ubuntu1) ... 233s Setting up libgcc-14-dev:arm64 (14.2.0-8ubuntu1) ... 233s Setting up libstdc++-14-dev:arm64 (14.2.0-8ubuntu1) ... 233s Setting up cpp-aarch64-linux-gnu (4:14.1.0-2ubuntu1) ... 233s Setting up python3-slow5 (0.7.0+dfsg-3) ... 233s Setting up cpp-14 (14.2.0-8ubuntu1) ... 233s Setting up cpp (4:14.1.0-2ubuntu1) ... 233s Setting up gcc-14-aarch64-linux-gnu (14.2.0-8ubuntu1) ... 233s Setting up gcc-aarch64-linux-gnu (4:14.1.0-2ubuntu1) ... 233s Setting up g++-14-aarch64-linux-gnu (14.2.0-8ubuntu1) ... 233s Setting up gcc-14 (14.2.0-8ubuntu1) ... 233s Setting up g++-aarch64-linux-gnu (4:14.1.0-2ubuntu1) ... 233s Setting up g++-14 (14.2.0-8ubuntu1) ... 233s Setting up gcc (4:14.1.0-2ubuntu1) ... 233s Setting up g++ (4:14.1.0-2ubuntu1) ... 233s update-alternatives: using /usr/bin/g++ to provide /usr/bin/c++ (c++) in auto mode 233s Setting up build-essential (12.10ubuntu1) ... 233s Setting up autopkgtest-satdep (0) ... 233s Processing triggers for man-db (2.12.1-3) ... 233s Processing triggers for libc-bin (2.40-1ubuntu3) ... 236s (Reading database ... 82069 files and directories currently installed.) 236s Removing autopkgtest-satdep (0) ... 239s autopkgtest [16:15:36]: test run-pkg-test: [----------------------- 239s Checking unit_test_ascii.c 240s Done! 240s Checking unit_test_binary.c 240s Done! 240s Checking unit_test_empty.c 240s Done! 240s Checking unit_test_enum.c 240s Done! 240s Checking unit_test_helpers.c 240s Done! 240s Checking unit_test_lossless.c 241s Done! 241s Checking unit_test_press.c 241s Done! 241s Checking unit_test_two_rg.c 241s Done! 241s autopkgtest [16:15:38]: test run-pkg-test: -----------------------] 242s autopkgtest [16:15:39]: test run-pkg-test: - - - - - - - - - - results - - - - - - - - - - 242s run-pkg-test PASS 242s autopkgtest [16:15:39]: @@@@@@@@@@@@@@@@@@@@ summary 242s run-pybinding-test PASS 242s run-pkg-test PASS 254s nova [W] Skipping flock in bos03-arm64 254s Creating nova instance adt-plucky-arm64-libslow5lib-20241114-161137-juju-7f2275-prod-proposed-migration-environment-20-dbf400bb-2650-4bd0-9b49-ee77208fc34d from image adt/ubuntu-plucky-arm64-server-20241114.img (UUID 4472f5f7-859f-4441-9e8e-9550fb35f210)... 254s nova [W] Skipping flock in bos03-arm64 254s Creating nova instance adt-plucky-arm64-libslow5lib-20241114-161137-juju-7f2275-prod-proposed-migration-environment-20-dbf400bb-2650-4bd0-9b49-ee77208fc34d from image adt/ubuntu-plucky-arm64-server-20241114.img (UUID 4472f5f7-859f-4441-9e8e-9550fb35f210)...