0s autopkgtest [17:59:52]: starting date and time: 2024-07-12 17:59:52+0000
  1s autopkgtest [17:59:53]: git checkout: fd3bed09 nova: allow more retries for quota issues
  1s autopkgtest [17:59:53]: host juju-7f2275-prod-proposed-migration-environment-2; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.dv7rx7xe/out --timeout-copy=6000 --setup-commands /home/ubuntu/autopkgtest-cloud/worker-config-production/setup-canonical.sh --apt-pocket=proposed=src:glibc --apt-upgrade porechop --timeout-short=300 --timeout-copy=20000 --timeout-build=20000 --env=ADT_TEST_TRIGGERS=glibc/2.39-3.1ubuntu3 -- ssh -s /home/ubuntu/autopkgtest/ssh-setup/nova -- --flavor autopkgtest --security-groups autopkgtest-juju-7f2275-prod-proposed-migration-environment-2@lcy02-108.secgroup --name adt-oracular-amd64-porechop-20240712-175946-juju-7f2275-prod-proposed-migration-environment-2-7b1627cd-ba5e-4e33-834e-7c2054bc62f8 --image adt/ubuntu-oracular-amd64-server --keyname testbed-juju-7f2275-prod-proposed-migration-environment-2 --net-id=net_prod-proposed-migration -e TERM=linux -e ''"'"'http_proxy=http://squid.internal:3128'"'"'' -e ''"'"'https_proxy=http://squid.internal:3128'"'"'' -e ''"'"'no_proxy=127.0.0.1,127.0.1.1,login.ubuntu.com,localhost,localdomain,novalocal,internal,archive.ubuntu.com,ports.ubuntu.com,security.ubuntu.com,ddebs.ubuntu.com,changelogs.ubuntu.com,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/
166s autopkgtest [18:02:38]: testbed dpkg architecture: amd64
167s autopkgtest [18:02:39]: testbed apt version: 2.9.6
167s autopkgtest [18:02:39]: @@@@@@@@@@@@@@@@@@@@ test bed setup
169s Get:1 http://ftpmaster.internal/ubuntu oracular-proposed InRelease [126 kB]
169s Get:2 http://ftpmaster.internal/ubuntu oracular-proposed/universe Sources [334 kB]
169s Get:3 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse Sources [2576 B]
169s Get:4 http://ftpmaster.internal/ubuntu oracular-proposed/restricted Sources [8548 B]
169s Get:5 http://ftpmaster.internal/ubuntu oracular-proposed/main Sources [46.6 kB]
169s Get:6 http://ftpmaster.internal/ubuntu oracular-proposed/main i386 Packages [70.9 kB]
169s Get:7 http://ftpmaster.internal/ubuntu oracular-proposed/main amd64 Packages [98.2 kB]
169s Get:8 http://ftpmaster.internal/ubuntu oracular-proposed/main amd64 c-n-f Metadata [2104 B]
169s Get:9 http://ftpmaster.internal/ubuntu oracular-proposed/restricted amd64 Packages [34.9 kB]
169s Get:10 http://ftpmaster.internal/ubuntu oracular-proposed/restricted i386 Packages [6244 B]
169s Get:11 http://ftpmaster.internal/ubuntu oracular-proposed/restricted amd64 c-n-f Metadata [368 B]
169s Get:12 http://ftpmaster.internal/ubuntu oracular-proposed/universe i386 Packages [224 kB]
169s Get:13 http://ftpmaster.internal/ubuntu oracular-proposed/universe amd64 Packages [368 kB]
169s Get:14 http://ftpmaster.internal/ubuntu oracular-proposed/universe amd64 c-n-f Metadata [9228 B]
169s Get:15 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse amd64 Packages [7644 B]
169s Get:16 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse i386 Packages [3052 B]
169s Get:17 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse amd64 c-n-f Metadata [276 B]
170s Fetched 1342 kB in 0s (4337 kB/s)
171s Reading package lists...
186s Reading package lists...
186s Building dependency tree...
186s Reading state information...
186s Calculating upgrade...
186s The following packages will be upgraded:
186s   libc-bin libc-dev-bin libc-devtools libc6 libc6-dev locales
186s 6 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.
186s Need to get 10.3 MB of archives.
186s After this operation, 34.8 kB of additional disk space will be used.
186s Get:1 http://ftpmaster.internal/ubuntu oracular-proposed/main amd64 libc-devtools amd64 2.39-3.1ubuntu3 [29.3 kB]
186s Get:2 http://ftpmaster.internal/ubuntu oracular-proposed/main amd64 libc6-dev amd64 2.39-3.1ubuntu3 [2120 kB]
187s Get:3 http://ftpmaster.internal/ubuntu oracular-proposed/main amd64 libc-dev-bin amd64 2.39-3.1ubuntu3 [20.4 kB]
187s Get:4 http://ftpmaster.internal/ubuntu oracular-proposed/main amd64 libc6 amd64 2.39-3.1ubuntu3 [3262 kB]
187s Get:5 http://ftpmaster.internal/ubuntu oracular-proposed/main amd64 libc-bin amd64 2.39-3.1ubuntu3 [680 kB]
187s Get:6 http://ftpmaster.internal/ubuntu oracular-proposed/main amd64 locales all 2.39-3.1ubuntu3 [4220 kB]
187s Preconfiguring packages ...
187s Fetched 10.3 MB in 0s (81.3 MB/s)
187s (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 ... 74486 files and directories currently installed.)
187s Preparing to unpack .../libc-devtools_2.39-3.1ubuntu3_amd64.deb ...
187s Unpacking libc-devtools (2.39-3.1ubuntu3) over (2.39-0ubuntu9) ...
187s Preparing to unpack .../libc6-dev_2.39-3.1ubuntu3_amd64.deb ...
187s Unpacking libc6-dev:amd64 (2.39-3.1ubuntu3) over (2.39-0ubuntu9) ...
187s Preparing to unpack .../libc-dev-bin_2.39-3.1ubuntu3_amd64.deb ...
187s Unpacking libc-dev-bin (2.39-3.1ubuntu3) over (2.39-0ubuntu9) ...
188s Preparing to unpack .../libc6_2.39-3.1ubuntu3_amd64.deb ...
188s Unpacking libc6:amd64 (2.39-3.1ubuntu3) over (2.39-0ubuntu9) ...
188s Setting up libc6:amd64 (2.39-3.1ubuntu3) ...
188s Error: Could not restart systemd, systemd binary not working
188s (Reading database ... 
(Reading database ... 5%
(Reading database ... 10%
(Reading database ... 15%
(Reading database ... 20%
(Reading database ... 25%
(Reading database ... 30%
(Reading database ... 35%
(Reading database ... 40%
(Reading database ... 45%
(Reading database ... 50%
(Reading database ... 55%
(Reading database ... 60%
(Reading database ... 65%
(Reading database ... 70%
(Reading database ... 75%
(Reading database ... 80%
(Reading database ... 85%
(Reading database ... 90%
(Reading database ... 95%
(Reading database ... 100%
(Reading database ... 74486 files and directories currently installed.)
188s Preparing to unpack .../libc-bin_2.39-3.1ubuntu3_amd64.deb ...
188s Unpacking libc-bin (2.39-3.1ubuntu3) over (2.39-0ubuntu9) ...
188s Setting up libc-bin (2.39-3.1ubuntu3) ...
188s (Reading database ... 
(Reading database ... 5%
(Reading database ... 10%
(Reading database ... 15%
(Reading database ... 20%
(Reading database ... 25%
(Reading database ... 30%
(Reading database ... 35%
(Reading database ... 40%
(Reading database ... 45%
(Reading database ... 50%
(Reading database ... 55%
(Reading database ... 60%
(Reading database ... 65%
(Reading database ... 70%
(Reading database ... 75%
(Reading database ... 80%
(Reading database ... 85%
(Reading database ... 90%
(Reading database ... 95%
(Reading database ... 100%
(Reading database ... 74486 files and directories currently installed.)
188s Preparing to unpack .../locales_2.39-3.1ubuntu3_all.deb ...
188s Unpacking locales (2.39-3.1ubuntu3) over (2.39-0ubuntu9) ...
188s Setting up locales (2.39-3.1ubuntu3) ...
189s Generating locales (this might take a while)...
191s   en_US.UTF-8... done
191s Generation complete.
191s Setting up libc-dev-bin (2.39-3.1ubuntu3) ...
191s Setting up libc-devtools (2.39-3.1ubuntu3) ...
191s Setting up libc6-dev:amd64 (2.39-3.1ubuntu3) ...
191s Processing triggers for man-db (2.12.1-2) ...
192s Processing triggers for systemd (256-1ubuntu1) ...
192s Reading package lists...
193s Building dependency tree...
193s Reading state information...
193s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.
194s Hit:1 http://ftpmaster.internal/ubuntu oracular-proposed InRelease
194s Hit:2 http://ftpmaster.internal/ubuntu oracular InRelease
194s Hit:3 http://ftpmaster.internal/ubuntu oracular-updates InRelease
194s Hit:4 http://ftpmaster.internal/ubuntu oracular-security InRelease
195s Reading package lists...
195s Reading package lists...
195s Building dependency tree...
195s Reading state information...
196s Calculating upgrade...
196s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.
196s Reading package lists...
196s Building dependency tree...
196s Reading state information...
196s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.
204s autopkgtest [18:03:16]: testbed running kernel: Linux 6.8.0-31-generic #31-Ubuntu SMP PREEMPT_DYNAMIC Sat Apr 20 00:40:06 UTC 2024
204s autopkgtest [18:03:16]: @@@@@@@@@@@@@@@@@@@@ apt-source porechop
208s Get:1 http://ftpmaster.internal/ubuntu oracular/universe porechop 0.2.4+dfsg-4 (dsc) [2067 B]
208s Get:2 http://ftpmaster.internal/ubuntu oracular/universe porechop 0.2.4+dfsg-4 (tar) [726 kB]
208s Get:3 http://ftpmaster.internal/ubuntu oracular/universe porechop 0.2.4+dfsg-4 (diff) [6100 B]
208s gpgv: Signature made Tue Oct 18 09:07:13 2022 UTC
208s gpgv:                using RSA key 33CB284313E90BD27DCB4523600316A6DC277476
208s gpgv: Can't check signature: No public key
208s dpkg-source: warning: cannot verify inline signature for ./porechop_0.2.4+dfsg-4.dsc: no acceptable signature found
208s autopkgtest [18:03:20]: testing package porechop version 0.2.4+dfsg-4
209s autopkgtest [18:03:21]: build not needed
209s autopkgtest [18:03:21]: test run-unit-test: preparing testbed
217s Reading package lists...
217s Building dependency tree...
217s Reading state information...
217s Starting pkgProblemResolver with broken count: 0
217s Starting 2 pkgProblemResolver with broken count: 0
217s Done
218s The following additional packages will be installed:
218s   porechop
218s The following NEW packages will be installed:
218s   autopkgtest-satdep porechop
218s 0 upgraded, 2 newly installed, 0 to remove and 0 not upgraded.
218s Need to get 58.1 kB/58.8 kB of archives.
218s After this operation, 231 kB of additional disk space will be used.
218s Get:1 /tmp/autopkgtest.IWUT3I/1-autopkgtest-satdep.deb autopkgtest-satdep amd64 0 [704 B]
218s Get:2 http://ftpmaster.internal/ubuntu oracular/universe amd64 porechop amd64 0.2.4+dfsg-4 [58.1 kB]
218s Fetched 58.1 kB in 0s (1873 kB/s)
218s Selecting previously unselected package porechop.
218s (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 ... 74486 files and directories currently installed.)
218s Preparing to unpack .../porechop_0.2.4+dfsg-4_amd64.deb ...
218s Unpacking porechop (0.2.4+dfsg-4) ...
218s Selecting previously unselected package autopkgtest-satdep.
218s Preparing to unpack .../1-autopkgtest-satdep.deb ...
218s Unpacking autopkgtest-satdep (0) ...
218s Setting up porechop (0.2.4+dfsg-4) ...
218s /usr/lib/python3/dist-packages/porechop/misc.py:261: SyntaxWarning: invalid escape sequence '\['
218s   row_str = re.sub('\033\[4m', '', row_str)
218s Setting up autopkgtest-satdep (0) ...
218s Processing triggers for man-db (2.12.1-2) ...
221s (Reading database ... 74506 files and directories currently installed.)
221s Removing autopkgtest-satdep (0) ...
228s autopkgtest [18:03:40]: test run-unit-test: [-----------------------
229s usage: porechop -i INPUT [-o OUTPUT]
229s                 [--format {auto,fasta,fastq,fasta.gz,fastq.gz}] [-v VERBOSITY]
229s                 [-t THREADS] [-b BARCODE_DIR]
229s                 [--barcode_threshold BARCODE_THRESHOLD]
229s                 [--barcode_diff BARCODE_DIFF] [--require_two_barcodes]
229s                 [--untrimmed] [--discard_unassigned]
229s                 [--adapter_threshold ADAPTER_THRESHOLD]
229s                 [--check_reads CHECK_READS] [--scoring_scheme SCORING_SCHEME]
229s                 [--end_size END_SIZE] [--min_trim_size MIN_TRIM_SIZE]
229s                 [--extra_end_trim EXTRA_END_TRIM]
229s                 [--end_threshold END_THRESHOLD] [--no_split]
229s                 [--discard_middle] [--middle_threshold MIDDLE_THRESHOLD]
229s                 [--extra_middle_trim_good_side EXTRA_MIDDLE_TRIM_GOOD_SIDE]
229s                 [--extra_middle_trim_bad_side EXTRA_MIDDLE_TRIM_BAD_SIDE]
229s                 [--min_split_read_size MIN_SPLIT_READ_SIZE] [-h] [--version]
229s 
229s Porechop: a tool for finding adapters in Oxford Nanopore reads, trimming them
229s from the ends and splitting reads with internal adapters
229s 
229s Main options:
229s   -i INPUT, --input INPUT
229s                           FASTA/FASTQ of input reads or a directory which will
229s                           be recursively searched for FASTQ files (required)
229s   -o OUTPUT, --output OUTPUT
229s                           Filename for FASTA or FASTQ of trimmed reads (if not
229s                           set, trimmed reads will be printed to stdout)
229s   --format {auto,fasta,fastq,fasta.gz,fastq.gz}
229s                           Output format for the reads - if auto, the format
229s                           will be chosen based on the output filename or the
229s                           input read format (default: auto)
229s   -v VERBOSITY, --verbosity VERBOSITY
229s                           Level of progress information: 0 = none, 1 = some, 2
229s                           = lots, 3 = full - output will go to stdout if reads
229s                           are saved to a file and stderr if reads are printed
229s                           to stdout (default: 1)
229s   -t THREADS, --threads THREADS
229s                           Number of threads to use for adapter alignment
229s                           (default: 2)
229s 
229s Barcode binning settings:
229s   Control the binning of reads based on barcodes (i.e. barcode
229s   demultiplexing)
229s 
229s   -b BARCODE_DIR, --barcode_dir BARCODE_DIR
229s                           Reads will be binned based on their barcode and
229s                           saved to separate files in this directory
229s                           (incompatible with --output)
229s   --barcode_threshold BARCODE_THRESHOLD
229s                           A read must have at least this percent identity to a
229s                           barcode to be binned (default: 75.0)
229s   --barcode_diff BARCODE_DIFF
229s                           If the difference between a read's best barcode
229s                           identity and its second-best barcode identity is
229s                           less than this value, it will not be put in a
229s                           barcode bin (to exclude cases which are too close to
229s                           call) (default: 5.0)
229s   --require_two_barcodes  Reads will only be put in barcode bins if they have
229s                           a strong match for the barcode on both their start
229s                           and end (default: a read can be binned with a match
229s                           at its start or end)
229s   --untrimmed             Bin reads but do not trim them (default: trim the
229s                           reads)
229s   --discard_unassigned    Discard unassigned reads (instead of creating a
229s                           "none" bin) (default: False)
229s 
229s Adapter search settings:
229s   Control how the program determines which adapter sets are present
229s 
229s   --adapter_threshold ADAPTER_THRESHOLD
229s                           An adapter set has to have at least this percent
229s                           identity to be labelled as present and trimmed off
229s                           (0 to 100) (default: 90.0)
229s   --check_reads CHECK_READS
229s                           This many reads will be aligned to all possible
229s                           adapters to determine which adapter sets are present
229s                           (default: 10000)
229s   --scoring_scheme SCORING_SCHEME
229s                           Comma-delimited string of alignment scores: match,
229s                           mismatch, gap open, gap extend (default: 3,-6,-5,-2)
229s 
229s End adapter settings:
229s   Control the trimming of adapters from read ends
229s 
229s   --end_size END_SIZE     The number of base pairs at each end of the read
229s                           which will be searched for adapter sequences
229s                           (default: 150)
229s   --min_trim_size MIN_TRIM_SIZE
229s                           Adapter alignments smaller than this will be ignored
229s                           (default: 4)
229s   --extra_end_trim EXTRA_END_TRIM
229s                           This many additional bases will be removed next to
229s                           adapters found at the ends of reads (default: 2)
229s   --end_threshold END_THRESHOLD
229s                           Adapters at the ends of reads must have at least
229s                           this percent identity to be removed (0 to 100)
229s                           (default: 75.0)
229s 
229s Middle adapter settings:
229s   Control the splitting of read from middle adapters
229s 
229s   --no_split              Skip splitting reads based on middle adapters
229s                           (default: split reads when an adapter is found in
229s                           the middle)
229s   --discard_middle        Reads with middle adapters will be discarded
229s                           (default: reads with middle adapters are split)
229s                           (required for reads to be used with Nanopolish, this
229s                           option is on by default when outputting reads into
229s                           barcode bins)
229s   --middle_threshold MIDDLE_THRESHOLD
229s                           Adapters in the middle of reads must have at least
229s                           this percent identity to be found (0 to 100)
229s                           (default: 90.0)
229s   --extra_middle_trim_good_side EXTRA_MIDDLE_TRIM_GOOD_SIDE
229s                           This many additional bases will be removed next to
229s                           middle adapters on their "good" side (default: 10)
229s   --extra_middle_trim_bad_side EXTRA_MIDDLE_TRIM_BAD_SIDE
229s                           This many additional bases will be removed next to
229s                           middle adapters on their "bad" side (default: 100)
229s   --min_split_read_size MIN_SPLIT_READ_SIZE
229s                           Post-split read pieces smaller than this many base
229s                           pairs will not be outputted (default: 1000)
229s 
229s Help:
229s   -h, --help              Show this help message and exit
229s   --version               Show program's version number and exit
229s autopkgtest [18:03:41]: test run-unit-test: -----------------------]
230s run-unit-test        PASS (superficial)
230s autopkgtest [18:03:42]: test run-unit-test:  - - - - - - - - - - results - - - - - - - - - -
231s autopkgtest [18:03:43]: @@@@@@@@@@@@@@@@@@@@ summary
231s run-unit-test        PASS (superficial)
248s nova [W] Skipping flock for amd64
248s Creating nova instance adt-oracular-amd64-porechop-20240712-175946-juju-7f2275-prod-proposed-migration-environment-2-7b1627cd-ba5e-4e33-834e-7c2054bc62f8 from image adt/ubuntu-oracular-amd64-server-20240712.img (UUID 9132249a-6053-4497-bc26-981612ca03ad)...