0s autopkgtest [20:51:36]: starting date and time: 2024-07-08 20:51:36+0000 0s autopkgtest [20:51:36]: git checkout: fd3bed09 nova: allow more retries for quota issues 0s autopkgtest [20:51:36]: host juju-7f2275-prod-proposed-migration-environment-3; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.gd_mx67w/out --timeout-copy=6000 --setup-commands /home/ubuntu/autopkgtest-cloud/worker-config-production/setup-canonical.sh --apt-pocket=proposed=src:mpi-defaults --apt-upgrade ray --timeout-short=300 --timeout-copy=20000 --timeout-build=20000 --env=ADT_TEST_TRIGGERS=mpi-defaults/1.17 -- ssh -s /home/ubuntu/autopkgtest/ssh-setup/nova -- --flavor autopkgtest --security-groups autopkgtest-juju-7f2275-prod-proposed-migration-environment-3@bos02-s390x-25.secgroup --name adt-oracular-s390x-ray-20240708-205136-juju-7f2275-prod-proposed-migration-environment-3-381163e1-2e1a-4d50-927a-5fc061ee2d3f --image adt/ubuntu-oracular-s390x-server --keyname testbed-juju-7f2275-prod-proposed-migration-environment-3 --net-id=net_prod-proposed-migration -e TERM=linux -e ''"'"'http_proxy=http://squid.internal:3128'"'"'' -e ''"'"'https_proxy=http://squid.internal:3128'"'"'' -e ''"'"'no_proxy=127.0.0.1,127.0.1.1,login.ubuntu.com,localhost,localdomain,novalocal,internal,archive.ubuntu.com,ports.ubuntu.com,security.ubuntu.com,ddebs.ubuntu.com,changelogs.ubuntu.com,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/ 126s autopkgtest [20:53:42]: testbed dpkg architecture: s390x 126s autopkgtest [20:53:42]: testbed apt version: 2.9.6 126s autopkgtest [20:53:42]: @@@@@@@@@@@@@@@@@@@@ test bed setup 127s Get:1 http://ftpmaster.internal/ubuntu oracular-proposed InRelease [126 kB] 127s Get:2 http://ftpmaster.internal/ubuntu oracular-proposed/main Sources [51.0 kB] 127s Get:3 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse Sources [3436 B] 127s Get:4 http://ftpmaster.internal/ubuntu oracular-proposed/restricted Sources [8548 B] 127s Get:5 http://ftpmaster.internal/ubuntu oracular-proposed/universe Sources [355 kB] 127s Get:6 http://ftpmaster.internal/ubuntu oracular-proposed/main s390x Packages [87.8 kB] 127s Get:7 http://ftpmaster.internal/ubuntu oracular-proposed/main s390x c-n-f Metadata [2548 B] 127s Get:8 http://ftpmaster.internal/ubuntu oracular-proposed/restricted s390x Packages [1368 B] 127s Get:9 http://ftpmaster.internal/ubuntu oracular-proposed/restricted s390x c-n-f Metadata [120 B] 127s Get:10 http://ftpmaster.internal/ubuntu oracular-proposed/universe s390x Packages [341 kB] 127s Get:11 http://ftpmaster.internal/ubuntu oracular-proposed/universe s390x c-n-f Metadata [8624 B] 127s Get:12 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse s390x Packages [1936 B] 127s Get:13 http://ftpmaster.internal/ubuntu oracular-proposed/multiverse s390x c-n-f Metadata [120 B] 128s Fetched 988 kB in 1s (1288 kB/s) 128s Reading package lists... 130s Reading package lists... 130s Building dependency tree... 130s Reading state information... 131s Calculating upgrade... 131s The following packages will be upgraded: 131s libnetplan1 lto-disabled-list netplan-generator netplan.io python3-netplan 131s 5 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 131s Need to get 288 kB of archives. 131s After this operation, 1024 B of additional disk space will be used. 131s Get:1 http://ftpmaster.internal/ubuntu oracular/main s390x netplan-generator s390x 1.0.1-1ubuntu2 [59.5 kB] 131s Get:2 http://ftpmaster.internal/ubuntu oracular/main s390x python3-netplan s390x 1.0.1-1ubuntu2 [23.0 kB] 131s Get:3 http://ftpmaster.internal/ubuntu oracular/main s390x netplan.io s390x 1.0.1-1ubuntu2 [66.2 kB] 131s Get:4 http://ftpmaster.internal/ubuntu oracular/main s390x libnetplan1 s390x 1.0.1-1ubuntu2 [127 kB] 131s Get:5 http://ftpmaster.internal/ubuntu oracular/main s390x lto-disabled-list all 52 [12.3 kB] 131s Fetched 288 kB in 0s (605 kB/s) 132s (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 ... 54702 files and directories currently installed.) 132s Preparing to unpack .../netplan-generator_1.0.1-1ubuntu2_s390x.deb ... 132s Adding 'diversion of /lib/systemd/system-generators/netplan to /lib/systemd/system-generators/netplan.usr-is-merged by netplan-generator' 132s Unpacking netplan-generator (1.0.1-1ubuntu2) over (1.0.1-1ubuntu1) ... 132s Preparing to unpack .../python3-netplan_1.0.1-1ubuntu2_s390x.deb ... 132s Unpacking python3-netplan (1.0.1-1ubuntu2) over (1.0.1-1ubuntu1) ... 132s Preparing to unpack .../netplan.io_1.0.1-1ubuntu2_s390x.deb ... 132s Unpacking netplan.io (1.0.1-1ubuntu2) over (1.0.1-1ubuntu1) ... 132s Preparing to unpack .../libnetplan1_1.0.1-1ubuntu2_s390x.deb ... 132s Unpacking libnetplan1:s390x (1.0.1-1ubuntu2) over (1.0.1-1ubuntu1) ... 132s Preparing to unpack .../lto-disabled-list_52_all.deb ... 132s Unpacking lto-disabled-list (52) over (51) ... 132s Setting up lto-disabled-list (52) ... 132s Setting up libnetplan1:s390x (1.0.1-1ubuntu2) ... 132s Setting up python3-netplan (1.0.1-1ubuntu2) ... 132s Setting up netplan-generator (1.0.1-1ubuntu2) ... 132s Removing 'diversion of /lib/systemd/system-generators/netplan to /lib/systemd/system-generators/netplan.usr-is-merged by netplan-generator' 132s Setting up netplan.io (1.0.1-1ubuntu2) ... 132s Processing triggers for libc-bin (2.39-0ubuntu9) ... 132s Processing triggers for man-db (2.12.1-2) ... 132s Processing triggers for dbus (1.14.10-4ubuntu4) ... 132s Reading package lists... 132s Building dependency tree... 132s Reading state information... 133s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 133s Hit:1 http://ftpmaster.internal/ubuntu oracular-proposed InRelease 133s Hit:2 http://ftpmaster.internal/ubuntu oracular InRelease 133s Hit:3 http://ftpmaster.internal/ubuntu oracular-updates InRelease 133s Hit:4 http://ftpmaster.internal/ubuntu oracular-security InRelease 134s Reading package lists... 134s Reading package lists... 134s Building dependency tree... 134s Reading state information... 134s Calculating upgrade... 135s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 135s Reading package lists... 135s Building dependency tree... 135s Reading state information... 135s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 138s autopkgtest [20:53:54]: testbed running kernel: Linux 6.8.0-31-generic #31-Ubuntu SMP Sat Apr 20 00:14:26 UTC 2024 138s autopkgtest [20:53:54]: @@@@@@@@@@@@@@@@@@@@ apt-source ray 140s Get:1 http://ftpmaster.internal/ubuntu oracular/universe ray 2.3.1-8build2 (dsc) [2192 B] 140s Get:2 http://ftpmaster.internal/ubuntu oracular/universe ray 2.3.1-8build2 (tar) [450 kB] 140s Get:3 http://ftpmaster.internal/ubuntu oracular/universe ray 2.3.1-8build2 (diff) [213 kB] 140s gpgv: Signature made Mon Apr 1 07:35:01 2024 UTC 140s gpgv: using RSA key A089FB36AAFBDAD5ACC1325069F790171A210984 140s gpgv: Can't check signature: No public key 140s dpkg-source: warning: cannot verify inline signature for ./ray_2.3.1-8build2.dsc: no acceptable signature found 141s autopkgtest [20:53:57]: testing package ray version 2.3.1-8build2 141s autopkgtest [20:53:57]: build not needed 142s autopkgtest [20:53:58]: test run-unit-test: preparing testbed 143s Reading package lists... 143s Building dependency tree... 143s Reading state information... 143s Starting pkgProblemResolver with broken count: 0 143s Starting 2 pkgProblemResolver with broken count: 0 143s Done 143s The following additional packages will be installed: 143s fontconfig libatomic1 libblas3 libcairo2 libdatrie1 143s libevent-pthreads-2.1-7t64 libfabric1 libgfortran5 libgomp1 libgraphite2-3 143s libharfbuzz0b libhwloc-plugins libhwloc15 libice6 liblapack3 libmunge2 143s libopenmpi3t64 libpango-1.0-0 libpangocairo-1.0-0 libpangoft2-1.0-0 143s libpaper-utils libpaper1 libpciaccess0 libpixman-1-0 libpmix2t64 143s librdmacm1t64 libsm6 libtcl8.6 libthai-data libthai0 libtk8.6 libxcb-render0 143s libxcb-shm0 libxft2 libxnvctrl0 libxrender1 libxss1 libxt6t64 143s mpi-default-bin ocl-icd-libopencl1 openmpi-bin openmpi-common r-base-core 143s ray ray-doc ray-extra unzip x11-common xdg-utils zip 143s Suggested packages: 143s tcl8.6 tk8.6 opencl-icd gfortran | fortran-compiler elpa-ess r-doc-info 143s | r-doc-pdf r-mathlib r-base-html 143s Recommended packages: 143s r-recommended r-base-dev r-doc-html libfile-mimeinfo-perl libnet-dbus-perl 143s libx11-protocol-perl x11-utils x11-xserver-utils 143s The following NEW packages will be installed: 143s autopkgtest-satdep fontconfig libatomic1 libblas3 libcairo2 libdatrie1 143s libevent-pthreads-2.1-7t64 libfabric1 libgfortran5 libgomp1 libgraphite2-3 143s libharfbuzz0b libhwloc-plugins libhwloc15 libice6 liblapack3 libmunge2 143s libopenmpi3t64 libpango-1.0-0 libpangocairo-1.0-0 libpangoft2-1.0-0 143s libpaper-utils libpaper1 libpciaccess0 libpixman-1-0 libpmix2t64 143s librdmacm1t64 libsm6 libtcl8.6 libthai-data libthai0 libtk8.6 libxcb-render0 143s libxcb-shm0 libxft2 libxnvctrl0 libxrender1 libxss1 libxt6t64 143s mpi-default-bin ocl-icd-libopencl1 openmpi-bin openmpi-common r-base-core 143s ray ray-doc ray-extra unzip x11-common xdg-utils zip 143s 0 upgraded, 51 newly installed, 0 to remove and 0 not upgraded. 143s Need to get 42.5 MB/42.5 MB of archives. 143s After this operation, 90.0 MB of additional disk space will be used. 143s Get:1 /tmp/autopkgtest.VRs63k/1-autopkgtest-satdep.deb autopkgtest-satdep s390x 0 [716 B] 144s Get:2 http://ftpmaster.internal/ubuntu oracular/main s390x fontconfig s390x 2.15.0-1.1ubuntu2 [191 kB] 144s Get:3 http://ftpmaster.internal/ubuntu oracular/main s390x libatomic1 s390x 14.1.0-1ubuntu1 [9378 B] 144s Get:4 http://ftpmaster.internal/ubuntu oracular/main s390x libblas3 s390x 3.12.0-3build1 [245 kB] 144s Get:5 http://ftpmaster.internal/ubuntu oracular/main s390x libpixman-1-0 s390x 0.42.2-1build1 [206 kB] 144s Get:6 http://ftpmaster.internal/ubuntu oracular/main s390x libxcb-render0 s390x 1.17.0-2 [17.0 kB] 144s Get:7 http://ftpmaster.internal/ubuntu oracular/main s390x libxcb-shm0 s390x 1.17.0-2 [5862 B] 144s Get:8 http://ftpmaster.internal/ubuntu oracular/main s390x libxrender1 s390x 1:0.9.10-1.1build1 [20.4 kB] 144s Get:9 http://ftpmaster.internal/ubuntu oracular/main s390x libcairo2 s390x 1.18.0-3build1 [589 kB] 144s Get:10 http://ftpmaster.internal/ubuntu oracular/main s390x libdatrie1 s390x 0.2.13-3build1 [20.6 kB] 144s Get:11 http://ftpmaster.internal/ubuntu oracular/main s390x libevent-pthreads-2.1-7t64 s390x 2.1.12-stable-10 [7870 B] 144s Get:12 http://ftpmaster.internal/ubuntu oracular/main s390x librdmacm1t64 s390x 52.0-2 [73.1 kB] 144s Get:13 http://ftpmaster.internal/ubuntu oracular/universe s390x libfabric1 s390x 1.17.0-3build2 [566 kB] 144s Get:14 http://ftpmaster.internal/ubuntu oracular/main s390x libgfortran5 s390x 14.1.0-1ubuntu1 [600 kB] 144s Get:15 http://ftpmaster.internal/ubuntu oracular/main s390x libgomp1 s390x 14.1.0-1ubuntu1 [151 kB] 144s Get:16 http://ftpmaster.internal/ubuntu oracular/main s390x libgraphite2-3 s390x 1.3.14-2ubuntu1 [79.8 kB] 144s Get:17 http://ftpmaster.internal/ubuntu oracular/main s390x libharfbuzz0b s390x 8.3.0-2build2 [515 kB] 144s Get:18 http://ftpmaster.internal/ubuntu oracular/universe s390x libhwloc15 s390x 2.10.0-1build1 [177 kB] 144s Get:19 http://ftpmaster.internal/ubuntu oracular/main s390x x11-common all 1:7.7+23ubuntu3 [21.7 kB] 144s Get:20 http://ftpmaster.internal/ubuntu oracular/main s390x libice6 s390x 2:1.0.10-1build3 [44.8 kB] 144s Get:21 http://ftpmaster.internal/ubuntu oracular/main s390x liblapack3 s390x 3.12.0-3build1 [2976 kB] 144s Get:22 http://ftpmaster.internal/ubuntu oracular/universe s390x libmunge2 s390x 0.5.15-4build1 [15.6 kB] 144s Get:23 http://ftpmaster.internal/ubuntu oracular/main s390x libpciaccess0 s390x 0.17-3build1 [19.0 kB] 144s Get:24 http://ftpmaster.internal/ubuntu oracular/main s390x libxnvctrl0 s390x 510.47.03-0ubuntu4 [12.7 kB] 144s Get:25 http://ftpmaster.internal/ubuntu oracular/universe s390x ocl-icd-libopencl1 s390x 2.3.2-1build1 [41.1 kB] 144s Get:26 http://ftpmaster.internal/ubuntu oracular/universe s390x libhwloc-plugins s390x 2.10.0-1build1 [16.3 kB] 144s Get:27 http://ftpmaster.internal/ubuntu oracular/universe s390x libpmix2t64 s390x 5.0.1-4.1build1 [728 kB] 144s Get:28 http://ftpmaster.internal/ubuntu oracular/universe s390x libopenmpi3t64 s390x 4.1.6-7ubuntu2 [2437 kB] 144s Get:29 http://ftpmaster.internal/ubuntu oracular/main s390x libthai-data all 0.1.29-2build1 [158 kB] 144s Get:30 http://ftpmaster.internal/ubuntu oracular/main s390x libthai0 s390x 0.1.29-2build1 [20.7 kB] 144s Get:31 http://ftpmaster.internal/ubuntu oracular/main s390x libpango-1.0-0 s390x 1.54.0+ds-1 [243 kB] 144s Get:32 http://ftpmaster.internal/ubuntu oracular/main s390x libpangoft2-1.0-0 s390x 1.54.0+ds-1 [43.4 kB] 144s Get:33 http://ftpmaster.internal/ubuntu oracular/main s390x libpangocairo-1.0-0 s390x 1.54.0+ds-1 [28.2 kB] 144s Get:34 http://ftpmaster.internal/ubuntu oracular/main s390x libpaper1 s390x 1.1.29build1 [13.4 kB] 144s Get:35 http://ftpmaster.internal/ubuntu oracular/main s390x libpaper-utils s390x 1.1.29build1 [8442 B] 144s Get:36 http://ftpmaster.internal/ubuntu oracular/main s390x libsm6 s390x 2:1.2.3-1build3 [17.7 kB] 144s Get:37 http://ftpmaster.internal/ubuntu oracular/main s390x libtcl8.6 s390x 8.6.14+dfsg-1build1 [1038 kB] 145s Get:38 http://ftpmaster.internal/ubuntu oracular/main s390x libxft2 s390x 2.3.6-1build1 [49.6 kB] 145s Get:39 http://ftpmaster.internal/ubuntu oracular/main s390x libxss1 s390x 1:1.2.3-1build3 [7396 B] 145s Get:40 http://ftpmaster.internal/ubuntu oracular/main s390x libtk8.6 s390x 8.6.14-1build1 [833 kB] 145s Get:41 http://ftpmaster.internal/ubuntu oracular/main s390x libxt6t64 s390x 1:1.2.1-1.2build1 [184 kB] 145s Get:42 http://ftpmaster.internal/ubuntu oracular/universe s390x openmpi-common all 4.1.6-7ubuntu2 [170 kB] 145s Get:43 http://ftpmaster.internal/ubuntu oracular/universe s390x openmpi-bin s390x 4.1.6-7ubuntu2 [84.5 kB] 145s Get:44 http://ftpmaster.internal/ubuntu oracular/main s390x zip s390x 3.0-13build1 [189 kB] 145s Get:45 http://ftpmaster.internal/ubuntu oracular/main s390x unzip s390x 6.0-28ubuntu5 [186 kB] 145s Get:46 http://ftpmaster.internal/ubuntu oracular/main s390x xdg-utils all 1.2.1-0ubuntu1 [67.5 kB] 145s Get:47 http://ftpmaster.internal/ubuntu oracular/universe s390x r-base-core s390x 4.4.1-1 [28.6 MB] 146s Get:48 http://ftpmaster.internal/ubuntu oracular-proposed/universe s390x mpi-default-bin s390x 1.17 [2296 B] 146s Get:49 http://ftpmaster.internal/ubuntu oracular/universe s390x ray s390x 2.3.1-8build2 [784 kB] 146s Get:50 http://ftpmaster.internal/ubuntu oracular/universe s390x ray-doc all 2.3.1-8build2 [35.1 kB] 146s Get:51 http://ftpmaster.internal/ubuntu oracular/universe s390x ray-extra all 2.3.1-8build2 [12.1 kB] 146s Preconfiguring packages ... 146s Fetched 42.5 MB in 2s (18.5 MB/s) 146s Selecting previously unselected package fontconfig. 146s (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 ... 54702 files and directories currently installed.) 146s Preparing to unpack .../00-fontconfig_2.15.0-1.1ubuntu2_s390x.deb ... 146s Unpacking fontconfig (2.15.0-1.1ubuntu2) ... 146s Selecting previously unselected package libatomic1:s390x. 146s Preparing to unpack .../01-libatomic1_14.1.0-1ubuntu1_s390x.deb ... 146s Unpacking libatomic1:s390x (14.1.0-1ubuntu1) ... 146s Selecting previously unselected package libblas3:s390x. 146s Preparing to unpack .../02-libblas3_3.12.0-3build1_s390x.deb ... 146s Unpacking libblas3:s390x (3.12.0-3build1) ... 146s Selecting previously unselected package libpixman-1-0:s390x. 146s Preparing to unpack .../03-libpixman-1-0_0.42.2-1build1_s390x.deb ... 146s Unpacking libpixman-1-0:s390x (0.42.2-1build1) ... 146s Selecting previously unselected package libxcb-render0:s390x. 146s Preparing to unpack .../04-libxcb-render0_1.17.0-2_s390x.deb ... 146s Unpacking libxcb-render0:s390x (1.17.0-2) ... 146s Selecting previously unselected package libxcb-shm0:s390x. 146s Preparing to unpack .../05-libxcb-shm0_1.17.0-2_s390x.deb ... 146s Unpacking libxcb-shm0:s390x (1.17.0-2) ... 146s Selecting previously unselected package libxrender1:s390x. 146s Preparing to unpack .../06-libxrender1_1%3a0.9.10-1.1build1_s390x.deb ... 146s Unpacking libxrender1:s390x (1:0.9.10-1.1build1) ... 146s Selecting previously unselected package libcairo2:s390x. 146s Preparing to unpack .../07-libcairo2_1.18.0-3build1_s390x.deb ... 146s Unpacking libcairo2:s390x (1.18.0-3build1) ... 146s Selecting previously unselected package libdatrie1:s390x. 146s Preparing to unpack .../08-libdatrie1_0.2.13-3build1_s390x.deb ... 146s Unpacking libdatrie1:s390x (0.2.13-3build1) ... 146s Selecting previously unselected package libevent-pthreads-2.1-7t64:s390x. 146s Preparing to unpack .../09-libevent-pthreads-2.1-7t64_2.1.12-stable-10_s390x.deb ... 146s Unpacking libevent-pthreads-2.1-7t64:s390x (2.1.12-stable-10) ... 146s Selecting previously unselected package librdmacm1t64:s390x. 146s Preparing to unpack .../10-librdmacm1t64_52.0-2_s390x.deb ... 146s Unpacking librdmacm1t64:s390x (52.0-2) ... 146s Selecting previously unselected package libfabric1:s390x. 146s Preparing to unpack .../11-libfabric1_1.17.0-3build2_s390x.deb ... 146s Unpacking libfabric1:s390x (1.17.0-3build2) ... 146s Selecting previously unselected package libgfortran5:s390x. 146s Preparing to unpack .../12-libgfortran5_14.1.0-1ubuntu1_s390x.deb ... 146s Unpacking libgfortran5:s390x (14.1.0-1ubuntu1) ... 146s Selecting previously unselected package libgomp1:s390x. 146s Preparing to unpack .../13-libgomp1_14.1.0-1ubuntu1_s390x.deb ... 146s Unpacking libgomp1:s390x (14.1.0-1ubuntu1) ... 146s Selecting previously unselected package libgraphite2-3:s390x. 146s Preparing to unpack .../14-libgraphite2-3_1.3.14-2ubuntu1_s390x.deb ... 146s Unpacking libgraphite2-3:s390x (1.3.14-2ubuntu1) ... 146s Selecting previously unselected package libharfbuzz0b:s390x. 146s Preparing to unpack .../15-libharfbuzz0b_8.3.0-2build2_s390x.deb ... 146s Unpacking libharfbuzz0b:s390x (8.3.0-2build2) ... 146s Selecting previously unselected package libhwloc15:s390x. 146s Preparing to unpack .../16-libhwloc15_2.10.0-1build1_s390x.deb ... 146s Unpacking libhwloc15:s390x (2.10.0-1build1) ... 146s Selecting previously unselected package x11-common. 146s Preparing to unpack .../17-x11-common_1%3a7.7+23ubuntu3_all.deb ... 146s Unpacking x11-common (1:7.7+23ubuntu3) ... 146s Selecting previously unselected package libice6:s390x. 146s Preparing to unpack .../18-libice6_2%3a1.0.10-1build3_s390x.deb ... 146s Unpacking libice6:s390x (2:1.0.10-1build3) ... 146s Selecting previously unselected package liblapack3:s390x. 146s Preparing to unpack .../19-liblapack3_3.12.0-3build1_s390x.deb ... 146s Unpacking liblapack3:s390x (3.12.0-3build1) ... 147s Selecting previously unselected package libmunge2:s390x. 147s Preparing to unpack .../20-libmunge2_0.5.15-4build1_s390x.deb ... 147s Unpacking libmunge2:s390x (0.5.15-4build1) ... 147s Selecting previously unselected package libpciaccess0:s390x. 147s Preparing to unpack .../21-libpciaccess0_0.17-3build1_s390x.deb ... 147s Unpacking libpciaccess0:s390x (0.17-3build1) ... 147s Selecting previously unselected package libxnvctrl0:s390x. 147s Preparing to unpack .../22-libxnvctrl0_510.47.03-0ubuntu4_s390x.deb ... 147s Unpacking libxnvctrl0:s390x (510.47.03-0ubuntu4) ... 147s Selecting previously unselected package ocl-icd-libopencl1:s390x. 147s Preparing to unpack .../23-ocl-icd-libopencl1_2.3.2-1build1_s390x.deb ... 147s Unpacking ocl-icd-libopencl1:s390x (2.3.2-1build1) ... 147s Selecting previously unselected package libhwloc-plugins:s390x. 147s Preparing to unpack .../24-libhwloc-plugins_2.10.0-1build1_s390x.deb ... 147s Unpacking libhwloc-plugins:s390x (2.10.0-1build1) ... 147s Selecting previously unselected package libpmix2t64:s390x. 147s Preparing to unpack .../25-libpmix2t64_5.0.1-4.1build1_s390x.deb ... 147s Unpacking libpmix2t64:s390x (5.0.1-4.1build1) ... 147s Selecting previously unselected package libopenmpi3t64:s390x. 147s Preparing to unpack .../26-libopenmpi3t64_4.1.6-7ubuntu2_s390x.deb ... 147s Unpacking libopenmpi3t64:s390x (4.1.6-7ubuntu2) ... 147s Selecting previously unselected package libthai-data. 147s Preparing to unpack .../27-libthai-data_0.1.29-2build1_all.deb ... 147s Unpacking libthai-data (0.1.29-2build1) ... 147s Selecting previously unselected package libthai0:s390x. 147s Preparing to unpack .../28-libthai0_0.1.29-2build1_s390x.deb ... 147s Unpacking libthai0:s390x (0.1.29-2build1) ... 147s Selecting previously unselected package libpango-1.0-0:s390x. 147s Preparing to unpack .../29-libpango-1.0-0_1.54.0+ds-1_s390x.deb ... 147s Unpacking libpango-1.0-0:s390x (1.54.0+ds-1) ... 147s Selecting previously unselected package libpangoft2-1.0-0:s390x. 147s Preparing to unpack .../30-libpangoft2-1.0-0_1.54.0+ds-1_s390x.deb ... 147s Unpacking libpangoft2-1.0-0:s390x (1.54.0+ds-1) ... 147s Selecting previously unselected package libpangocairo-1.0-0:s390x. 147s Preparing to unpack .../31-libpangocairo-1.0-0_1.54.0+ds-1_s390x.deb ... 147s Unpacking libpangocairo-1.0-0:s390x (1.54.0+ds-1) ... 147s Selecting previously unselected package libpaper1:s390x. 147s Preparing to unpack .../32-libpaper1_1.1.29build1_s390x.deb ... 147s Unpacking libpaper1:s390x (1.1.29build1) ... 147s Selecting previously unselected package libpaper-utils. 147s Preparing to unpack .../33-libpaper-utils_1.1.29build1_s390x.deb ... 147s Unpacking libpaper-utils (1.1.29build1) ... 147s Selecting previously unselected package libsm6:s390x. 147s Preparing to unpack .../34-libsm6_2%3a1.2.3-1build3_s390x.deb ... 147s Unpacking libsm6:s390x (2:1.2.3-1build3) ... 147s Selecting previously unselected package libtcl8.6:s390x. 147s Preparing to unpack .../35-libtcl8.6_8.6.14+dfsg-1build1_s390x.deb ... 147s Unpacking libtcl8.6:s390x (8.6.14+dfsg-1build1) ... 147s Selecting previously unselected package libxft2:s390x. 147s Preparing to unpack .../36-libxft2_2.3.6-1build1_s390x.deb ... 147s Unpacking libxft2:s390x (2.3.6-1build1) ... 147s Selecting previously unselected package libxss1:s390x. 147s Preparing to unpack .../37-libxss1_1%3a1.2.3-1build3_s390x.deb ... 147s Unpacking libxss1:s390x (1:1.2.3-1build3) ... 147s Selecting previously unselected package libtk8.6:s390x. 147s Preparing to unpack .../38-libtk8.6_8.6.14-1build1_s390x.deb ... 147s Unpacking libtk8.6:s390x (8.6.14-1build1) ... 147s Selecting previously unselected package libxt6t64:s390x. 147s Preparing to unpack .../39-libxt6t64_1%3a1.2.1-1.2build1_s390x.deb ... 147s Unpacking libxt6t64:s390x (1:1.2.1-1.2build1) ... 147s Selecting previously unselected package openmpi-common. 147s Preparing to unpack .../40-openmpi-common_4.1.6-7ubuntu2_all.deb ... 147s Unpacking openmpi-common (4.1.6-7ubuntu2) ... 147s Selecting previously unselected package openmpi-bin. 147s Preparing to unpack .../41-openmpi-bin_4.1.6-7ubuntu2_s390x.deb ... 147s Unpacking openmpi-bin (4.1.6-7ubuntu2) ... 147s Selecting previously unselected package zip. 147s Preparing to unpack .../42-zip_3.0-13build1_s390x.deb ... 147s Unpacking zip (3.0-13build1) ... 147s Selecting previously unselected package unzip. 147s Preparing to unpack .../43-unzip_6.0-28ubuntu5_s390x.deb ... 147s Unpacking unzip (6.0-28ubuntu5) ... 147s Selecting previously unselected package xdg-utils. 147s Preparing to unpack .../44-xdg-utils_1.2.1-0ubuntu1_all.deb ... 147s Unpacking xdg-utils (1.2.1-0ubuntu1) ... 147s Selecting previously unselected package r-base-core. 147s Preparing to unpack .../45-r-base-core_4.4.1-1_s390x.deb ... 147s Unpacking r-base-core (4.4.1-1) ... 148s Selecting previously unselected package mpi-default-bin. 148s Preparing to unpack .../46-mpi-default-bin_1.17_s390x.deb ... 148s Unpacking mpi-default-bin (1.17) ... 148s Selecting previously unselected package ray. 148s Preparing to unpack .../47-ray_2.3.1-8build2_s390x.deb ... 148s Unpacking ray (2.3.1-8build2) ... 148s Selecting previously unselected package ray-doc. 148s Preparing to unpack .../48-ray-doc_2.3.1-8build2_all.deb ... 148s Unpacking ray-doc (2.3.1-8build2) ... 148s Selecting previously unselected package ray-extra. 148s Preparing to unpack .../49-ray-extra_2.3.1-8build2_all.deb ... 148s Unpacking ray-extra (2.3.1-8build2) ... 148s Selecting previously unselected package autopkgtest-satdep. 148s Preparing to unpack .../50-1-autopkgtest-satdep.deb ... 148s Unpacking autopkgtest-satdep (0) ... 148s Setting up libgraphite2-3:s390x (1.3.14-2ubuntu1) ... 148s Setting up libpixman-1-0:s390x (0.42.2-1build1) ... 148s Setting up libpaper1:s390x (1.1.29build1) ... 148s 148s Creating config file /etc/papersize with new version 148s Setting up ray-doc (2.3.1-8build2) ... 148s Setting up libpciaccess0:s390x (0.17-3build1) ... 148s Setting up fontconfig (2.15.0-1.1ubuntu2) ... 150s Regenerating fonts cache... done. 150s Setting up libxrender1:s390x (1:0.9.10-1.1build1) ... 150s Setting up libdatrie1:s390x (0.2.13-3build1) ... 150s Setting up libxcb-render0:s390x (1.17.0-2) ... 150s Setting up libevent-pthreads-2.1-7t64:s390x (2.1.12-stable-10) ... 150s Setting up unzip (6.0-28ubuntu5) ... 150s Setting up x11-common (1:7.7+23ubuntu3) ... 150s Setting up libxcb-shm0:s390x (1.17.0-2) ... 150s Setting up libpaper-utils (1.1.29build1) ... 150s Setting up libgomp1:s390x (14.1.0-1ubuntu1) ... 150s Setting up libcairo2:s390x (1.18.0-3build1) ... 150s Setting up libxnvctrl0:s390x (510.47.03-0ubuntu4) ... 150s Setting up zip (3.0-13build1) ... 150s Setting up libblas3:s390x (3.12.0-3build1) ... 150s update-alternatives: using /usr/lib/s390x-linux-gnu/blas/libblas.so.3 to provide /usr/lib/s390x-linux-gnu/libblas.so.3 (libblas.so.3-s390x-linux-gnu) in auto mode 150s Setting up libmunge2:s390x (0.5.15-4build1) ... 150s Setting up libhwloc15:s390x (2.10.0-1build1) ... 150s Setting up libatomic1:s390x (14.1.0-1ubuntu1) ... 150s Setting up libtcl8.6:s390x (8.6.14+dfsg-1build1) ... 150s Setting up libgfortran5:s390x (14.1.0-1ubuntu1) ... 150s Setting up ocl-icd-libopencl1:s390x (2.3.2-1build1) ... 150s Setting up openmpi-common (4.1.6-7ubuntu2) ... 150s Setting up librdmacm1t64:s390x (52.0-2) ... 150s Setting up libharfbuzz0b:s390x (8.3.0-2build2) ... 150s Setting up libthai-data (0.1.29-2build1) ... 150s Setting up libxss1:s390x (1:1.2.3-1build3) ... 150s Setting up xdg-utils (1.2.1-0ubuntu1) ... 150s update-alternatives: using /usr/bin/xdg-open to provide /usr/bin/open (open) in auto mode 150s Setting up libfabric1:s390x (1.17.0-3build2) ... 150s Setting up libice6:s390x (2:1.0.10-1build3) ... 150s Setting up liblapack3:s390x (3.12.0-3build1) ... 150s update-alternatives: using /usr/lib/s390x-linux-gnu/lapack/liblapack.so.3 to provide /usr/lib/s390x-linux-gnu/liblapack.so.3 (liblapack.so.3-s390x-linux-gnu) in auto mode 150s Setting up libxft2:s390x (2.3.6-1build1) ... 150s Setting up libtk8.6:s390x (8.6.14-1build1) ... 150s Setting up libhwloc-plugins:s390x (2.10.0-1build1) ... 150s Setting up libthai0:s390x (0.1.29-2build1) ... 150s Setting up libpmix2t64:s390x (5.0.1-4.1build1) ... 150s Setting up libopenmpi3t64:s390x (4.1.6-7ubuntu2) ... 150s Setting up libsm6:s390x (2:1.2.3-1build3) ... 150s Setting up openmpi-bin (4.1.6-7ubuntu2) ... 150s update-alternatives: using /usr/bin/mpirun.openmpi to provide /usr/bin/mpirun (mpirun) in auto mode 150s update-alternatives: using /usr/bin/mpicc.openmpi to provide /usr/bin/mpicc (mpi) in auto mode 150s Setting up libpango-1.0-0:s390x (1.54.0+ds-1) ... 150s Setting up mpi-default-bin (1.17) ... 150s Setting up libxt6t64:s390x (1:1.2.1-1.2build1) ... 150s Setting up ray (2.3.1-8build2) ... 150s Setting up libpangoft2-1.0-0:s390x (1.54.0+ds-1) ... 150s Setting up libpangocairo-1.0-0:s390x (1.54.0+ds-1) ... 150s Setting up r-base-core (4.4.1-1) ... 150s 150s Creating config file /etc/R/Renviron with new version 150s Setting up ray-extra (2.3.1-8build2) ... 150s Setting up autopkgtest-satdep (0) ... 150s Processing triggers for man-db (2.12.1-2) ... 151s Processing triggers for install-info (7.1-3build2) ... 151s Processing triggers for libc-bin (2.39-0ubuntu9) ... 154s (Reading database ... 57248 files and directories currently installed.) 154s Removing autopkgtest-satdep (0) ... 155s autopkgtest [20:54:11]: test run-unit-test: [----------------------- 155s 155s ************************************************** 155s This program comes with ABSOLUTELY NO WARRANTY. 155s This is free software, and you are welcome to redistribute it 155s under certain conditions; see "LICENSE.txt" for details. 155s ************************************************** 155s 155s Ray Copyright (C) 2010, 2011, 2012, 2013 Sébastien Boisvert 155s Centre de recherche en infectiologie de l'Université Laval 155s Project funded by the Canadian Institutes of Health Research (Doctoral award 200902CGM-204212-172830 to S.B.) 155s http://denovoassembler.sf.net/ 155s 155s References to cite: 155s 155s Sébastien Boisvert, Frédéric Raymond, Élénie Godzaridis, François Laviolette and Jacques Corbeil. 155s Ray Meta: scalable de novo metagenome assembly and profiling. 155s Genome Biology (BioMed Central Ltd). 155s 13:R122, Published: 22 December 2012 155s http://dx.doi.org/doi:10.1186/gb-2012-13-12-r122 155s 155s Sébastien Boisvert, François Laviolette & Jacques Corbeil. 155s Ray: simultaneous assembly of reads from a mix of high-throughput sequencing technologies. 155s Journal of Computational Biology (Mary Ann Liebert, Inc. publishers, New York, U.S.A.). 155s November 2010, Volume 17, Issue 11, Pages 1519-1533. 155s http://dx.doi.org/doi:10.1089/cmb.2009.0238 155s 155s Ray version 2.3.1 155s License for Ray: GNU General Public License version 3 155s RayPlatform version: 2.0.1 155s License for RayPlatform: GNU Lesser General Public License version 3 155s 155s MAXKMERLENGTH: 32 155s Maximum coverage depth stored by CoverageDepth: 4294967295 155s MAXIMUM_MESSAGE_SIZE_IN_BYTES: 4000 bytes 155s FORCE_PACKING = n 155s ASSERT = n 155s HAVE_LIBZ = y 155s HAVE_LIBBZ2 = y 155s PROFILER_COLLECT = n 155s MINIRANKS = y 155s CLOCK_GETTIME = n 155s __linux__ = y 155s _MSC_VER = n 155s __GNUC__ = y 155s RAY_32_BITS = n 155s RAY_64_BITS = y 155s MPI standard version: MPI 3.1 155s MPI library: Open-MPI 4.1.6 155s Compiler: GNU gcc/g++ 13.2.0 155s MPI I/O: n 155s 155s 155s -k (to set the k-mer size) 155s Value: 31 155s 155s 155s Paired library # 0 155s -p (paired-end sequences) 155s Left sequences: ecoli_1K_1.fq 155s Right sequences: ecoli_1K_2.fq 155s Average length: automatic detection 155s Standard deviation: automatic detection 155s 155s Ray command: 155s mpiexec -n 1 Ray \ 155s -k \ 155s 31 \ 155s -p \ 155s ecoli_1K_1.fq \ 155s ecoli_1K_2.fq \ 155s -o \ 155s test1 155s 155s Rank 0 wrote test1/RayCommand.txt 155s 155s k-mer length: 31 155s Rank 0: assembler memory usage: 41948 KiB 155s Rank 0: assembler memory usage: 107620 KiB 155s Rank 0: Rank= 0 Size= 1 ProcessIdentifier= 2915 155s Rank 0: testing the network, please wait... 155s 155s Rank 0 is testing the network [0/1000] 155s Rank 0 is testing the network [1000/1000] 155s Rank 0: mode round trip latency when requesting a reply for a message of 4000 bytes is 1 microseconds (10^-6 seconds) 155s Rank 0: average round trip latency when requesting a reply for a message of 4000 bytes is 1 microseconds (10^-6 seconds) 155s 155s Rank 0 wrote test1/NetworkTest.txt 155s 155s 155s *** 155s Step: Network testing 155s Date: Mon Jul 8 20:54:11 2024 155s Elapsed time: 0 seconds 155s Since beginning: 0 seconds 155s *** 155s 155s 155s Rank 0 is fetching file ecoli_1K_1.fq with lazy loading (please wait...) 155s Rank 0: File ecoli_1K_1.fq (Number 0) has 2054 sequences 155s Rank 0 is fetching file ecoli_1K_2.fq with lazy loading (please wait...) 155s Rank 0: File ecoli_1K_2.fq (Number 1) has 2054 sequences 155s Rank 0 wrote test1/NumberOfSequences.txt 155s Rank 0 wrote test1/SequencePartition.txt 155s 155s *** 155s Step: Counting sequences to assemble 155s Date: Mon Jul 8 20:54:11 2024 155s Elapsed time: 0 seconds 155s Since beginning: 0 seconds 155s *** 155s 155s 155s Rank 0 is loading sequence reads 155s Rank 0 : partition is [0;4107], 4108 sequence reads 155s Rank 0 is fetching file ecoli_1K_1.fq with lazy loading (please wait...) 155s Rank 0 has 0 sequence reads 155s Rank 0: assembler memory usage: 120628 KiB 155s Rank 0 is fetching file ecoli_1K_2.fq with lazy loading (please wait...) 155s Rank 0 has 4108 sequence reads (completed) 155s 155s *** 155s Step: Sequence loading 155s Date: Mon Jul 8 20:54:11 2024 155s Elapsed time: 0 seconds 155s Since beginning: 0 seconds 155s *** 155s 155s 155s [BloomFilter] allocated 254696 bytes for table with 2037568 bits 155s Rank 0 created its Bloom filter 156s Rank 0 is counting k-mers in sequence reads [1/4108] 156s Rank 0 is counting k-mers in sequence reads [4108/4108] (completed) 156s Rank 0 : VirtualCommunicator (service provided by BufferedData): 230710 virtual messages generated 462 real messages (0.200251%) 156s 156s 156s *** 156s Step: K-mer counting 156s Date: Mon Jul 8 20:54:11 2024 156s Elapsed time: 0 seconds 156s Since beginning: 0 seconds 156s *** 156s 156s 156s Rank 0 number of set bits in the Bloom filter: [ 7801 / 2037568 ] (0.382858%) 156s Rank 0 destroyed its Bloom filter 156s Rank 0 has 1954 k-mers (completed) 156s [BloomFilter] Rank 0: k-mers sampled -> 1954, k-mers dropped -> 0 (0%), k-mers accepted -> 1954 (100%) 156s Rank 0: assembler memory usage: 117024 KiB 157s 157s 157s Rank 0: the minimum coverage is 3 157s Rank 0: the peak coverage is 3 157s Warning: no peak observed in the k-mer coverage distribution. 157s to deal with the sequencing error rate, try to lower the k-mer length (-k) 157s If you are using RNA-Seq or metagenomic data, then you can ignore this warning. 157s 157s *** 157s Step: Coverage distribution analysis 157s Date: Mon Jul 8 20:54:13 2024 157s Elapsed time: 2 seconds 157s Since beginning: 2 seconds 157s *** 157s 157s 157s 157s Rank 0 is adding edges [1/4108] 157s Rank 0 is adding edges [4108/4108] (completed) 157s Rank 0 : VirtualCommunicator (service provided by BufferedData): 453238 virtual messages generated 1813 real messages (0.400011%) 157s Rank 0 : VirtualCommunicator (service provided by BufferedData): 453238 virtual messages generated 1813 real messages (0.400011%) 157s 157s *** 157s Step: Graph construction 157s Date: Mon Jul 8 20:54:13 2024 157s Elapsed time: 0 seconds 157s Since beginning: 2 seconds 157s *** 157s 157s 157s Rank 0 has 1954 vertices (completed) 157s Rank 0: assembler memory usage: 117024 KiB 158s Rank 0 is purging edges [1/1954] 158s Rank 0 is purging edges [1954/1954] (completed) 158s Rank 0: assembler memory usage: 117552 KiB 158s VirtualProcessor: completed jobs: 1954 158s Rank 0 : VirtualCommunicator (service provided by VirtualCommunicator): 3904 virtual messages generated 11 real messages (0.281762%) 159s Rank 0 wrote test1/degreeDistribution.txt 159s 159s *** 159s Step: Null edge purging 159s Date: Mon Jul 8 20:54:15 2024 159s Elapsed time: 2 seconds 159s Since beginning: 4 seconds 159s *** 159s 159s 159s Rank 0 is selecting optimal read markers [1/4108] 159s Rank 0: assembler memory usage: 117552 KiB 160s Rank 0 is selecting optimal read markers [4108/4108] (completed) 160s Rank 0: peak number of workers: 599, maximum: 32768 160s Rank 0 : VirtualCommunicator (service provided by VirtualCommunicator): 238890 virtual messages generated 609 real messages (0.254929%) 160s Rank 0: assembler memory usage: 125716 KiB 160s Rank 0: Freeing unused assembler memory: 4096 KiB freed 160s Rank 0: assembler memory usage: 125716 KiB 160s 160s *** 160s Step: Selection of optimal read markers 160s Date: Mon Jul 8 20:54:16 2024 160s Elapsed time: 1 seconds 160s Since beginning: 5 seconds 160s *** 160s 160s 160s Rank 0: memory usage for optimal read markers= 4096 KiB 160s Rank 0 is creating seeds [1/1954] 160s Rank 0: assembler memory usage: 125716 KiB 161s Rank 0 has 1 seeds 161s Rank 0 is creating seeds [1954/1954] (completed) 161s Rank 0: peak number of workers: 746, maximum: 32768 161s Rank 0 : VirtualCommunicator (service provided by VirtualCommunicator): 13612 virtual messages generated 1720 real messages (12.6359%) 161s Rank 0 runtime statistics for seeding algorithm: 161s Rank 0 Skipped paths because of dead end for head: 0 161s Rank 0 Skipped paths because of dead end for tail: 0 161s Rank 0 Skipped paths because of two dead ends: 0 161s Rank 0 Skipped paths because of bubble weak component: 0 161s Rank 0 Skipped paths because of short length: 1952 161s Rank 0 Skipped paths because of bad ownership: 1 161s Rank 0 Skipped paths because of low coverage: 0 161s Rank 0 Eligible paths: 1 161s Rank 0: assembler memory usage: 125716 KiB 161s Rank 0 has 1 seeds to register. 161s Rank 0 registered 0/1 161s Rank 0 registered 0/1 161s Rank 0 registered its seeds 161s VirtualProcessor: completed jobs: 0 161s Rank 0 : VirtualCommunicator (service provided by VirtualCommunicator): 0 virtual messages generated 0 real messages (0%) 162s Rank 0 freed 4194304 bytes from the path memory pool (chunks: 1) 172s Rank 0: gossiping generated 0 messages (gossips: 0 ---> 0) 172s Rank 0 merged its seeds: 1 seeds -> 1 seeds 172s 172s *** 172s Step: Detection of assembly seeds 172s Date: Mon Jul 8 20:54:28 2024 172s Elapsed time: 12 seconds 172s Since beginning: 17 seconds 172s *** 172s 172s 172s Rank 0 is calculating library lengths [1/1] 172s Rank 0 detected 1737 library lengths 172s Rank 0 is calculating library lengths [1/1] (completed) 172s Rank 0: peak number of workers: 1, maximum: 32768 172s Rank 0 : VirtualCommunicator (service provided by VirtualCommunicator): 7997 virtual messages generated 7997 real messages (100%) 172s Rank 0: assembler memory usage: 162584 KiB 172s Rank 0 : VirtualCommunicator (service provided by BufferedData): 67 virtual messages generated 1 real messages (1.49254%) 172s 172s Mode= 2 signalAverage= 9 172s CURRENT IS NOISE, 244 172s GOT HIT 212 172s 172s 172s Library # 0 (Automatic) -> average length: 214 and standard deviation: 10 172s 172s *** 172s Step: Estimation of outer distances for paired reads 172s Date: Mon Jul 8 20:54:28 2024 172s Elapsed time: 0 seconds 172s Since beginning: 17 seconds 172s *** 172s 172s 172s Rank 0 starts on seed 0, length is 845, flow 0 [0/1] 172s Rank 0 traversed 1000 nucleotide symbols 172s Rank 0: assembler memory usage: 166680 KiB 172s Rank 0 is extending seeds [1/1] (completed) 172s Rank 0 extended 1 seeds out of 1 (100.00%) 172s Rank 0: assembler memory usage: 158488 KiB 172s Rank 0 starting fusions 172s 172s *** 172s Step: Bidirectional extension of seeds 172s Date: Mon Jul 8 20:54:28 2024 172s Elapsed time: 0 seconds 172s Since beginning: 17 seconds 172s *** 172s 172s 172s Rank 0: starting clear step. cycleNumber= 0 173s Rank 0 adding 0 new fusions 173s Rank 0 cleared, 1 paths 173s Rank 0: starting distribution step 173s Rank 0 is distributing fusions [1/1] 173s Rank 0: assembler memory usage: 158488 KiB 173s Date: Mon Jul 8 20:54:29 2024 173s Rank 0 is distributing fusions [1/1] (completed) 173s Rank 0 : VirtualCommunicator (service provided by BufferedData): 970 virtual messages generated 6 real messages (0.618557%) 173s Rank 0: assembler memory usage: 162584 KiB 173s Date: Mon Jul 8 20:54:29 2024 173s Rank 0 tells others to compute fusions. 173s Rank 0 FusionTaskCreator assignNextTask [0/2] 173s Rank 0: assembler memory usage: 162584 KiB 173s Date: Mon Jul 8 20:54:29 2024 174s Rank 0 FusionTaskCreator processWorkerResult [0/2] 174s Rank 0: assembler memory usage: 162584 KiB 174s Date: Mon Jul 8 20:54:29 2024 174s Rank 0 FusionTaskCreator [2/2] 174s Statistics: all paths: 1 eliminated during fusing: 0 174s Rank 0: assembler memory usage: 162584 KiB 174s VirtualProcessor: completed jobs: 2 174s Rank 0 : VirtualCommunicator (service provided by VirtualCommunicator): 10907 virtual messages generated 10907 real messages (100%) 174s Rank 0: starting clear step. cycleNumber= 1 175s Rank 0 adding 0 new fusions 175s Rank 0 cleared, 1 paths 175s Rank 0 is distributing fusions [1/1] 175s Rank 0: assembler memory usage: 162584 KiB 175s Date: Mon Jul 8 20:54:31 2024 175s Rank 0 is distributing fusions [1/1] (completed) 175s Rank 0 : VirtualCommunicator (service provided by BufferedData): 970 virtual messages generated 6 real messages (0.618557%) 175s Rank 0: assembler memory usage: 162584 KiB 175s Date: Mon Jul 8 20:54:31 2024 175s Rank 0 JoinerTaskCreator assignNextTask [0/2] 175s Rank 0: assembler memory usage: 162584 KiB 175s Date: Mon Jul 8 20:54:31 2024 175s Rank 0 JoinerTaskCreator processWorkerResult [0/2] 175s Rank 0: assembler memory usage: 162584 KiB 175s Date: Mon Jul 8 20:54:31 2024 175s Rank 0 JoinerTaskCreator [2/2] 175s Statistics: all paths: 1 eliminated during joining: 0 175s Rank 0: assembler memory usage: 162584 KiB 175s Date: Mon Jul 8 20:54:31 2024 175s VirtualProcessor: completed jobs: 2 175s Rank 0 : VirtualCommunicator (service provided by VirtualCommunicator): 13817 virtual messages generated 13817 real messages (100%) 176s Rank 0 adding 0 new fusions 176s Rank 0 cleared, 1 paths 176s Rank 0: starting distribution step 176s Rank 0 is distributing fusions [1/1] 176s Rank 0: assembler memory usage: 162584 KiB 176s Date: Mon Jul 8 20:54:32 2024 176s Rank 0 is distributing fusions [1/1] (completed) 176s Rank 0 : VirtualCommunicator (service provided by BufferedData): 970 virtual messages generated 6 real messages (0.618557%) 176s Rank 0: assembler memory usage: 162584 KiB 176s Date: Mon Jul 8 20:54:32 2024 176s Rank 0 tells others to compute fusions. 176s Rank 0 FusionTaskCreator assignNextTask [0/2] 176s Rank 0: assembler memory usage: 162584 KiB 176s Date: Mon Jul 8 20:54:32 2024 176s Rank 0 FusionTaskCreator processWorkerResult [0/2] 176s Rank 0: assembler memory usage: 162584 KiB 176s Date: Mon Jul 8 20:54:32 2024 176s Rank 0 FusionTaskCreator [2/2] 176s Statistics: all paths: 1 eliminated during fusing: 0 176s Rank 0: assembler memory usage: 162584 KiB 176s VirtualProcessor: completed jobs: 2 176s Rank 0 : VirtualCommunicator (service provided by VirtualCommunicator): 16727 virtual messages generated 16727 real messages (100%) 176s Rank 0: starting clear step. cycleNumber= 2 177s Rank 0 adding 0 new fusions 177s Rank 0 cleared, 1 paths 177s Rank 0 is distributing fusions [1/1] 177s Rank 0: assembler memory usage: 162584 KiB 177s Date: Mon Jul 8 20:54:33 2024 177s Rank 0 is distributing fusions [1/1] (completed) 177s Rank 0 : VirtualCommunicator (service provided by BufferedData): 970 virtual messages generated 6 real messages (0.618557%) 177s Rank 0: assembler memory usage: 162584 KiB 177s Date: Mon Jul 8 20:54:33 2024 177s Rank 0 JoinerTaskCreator assignNextTask [0/2] 177s Rank 0: assembler memory usage: 162584 KiB 177s Date: Mon Jul 8 20:54:33 2024 177s Rank 0 JoinerTaskCreator processWorkerResult [0/2] 177s Rank 0: assembler memory usage: 162584 KiB 177s Date: Mon Jul 8 20:54:33 2024 177s Rank 0 JoinerTaskCreator [2/2] 177s Statistics: all paths: 1 eliminated during joining: 0 177s Rank 0: assembler memory usage: 162584 KiB 177s Date: Mon Jul 8 20:54:33 2024 177s VirtualProcessor: completed jobs: 2 177s Rank 0 : VirtualCommunicator (service provided by VirtualCommunicator): 19637 virtual messages generated 19637 real messages (100%) 178s Rank 0 adding 0 new fusions 178s Rank 0 cleared, 1 paths 178s Rank 0: starting distribution step 178s Rank 0 is distributing fusions [1/1] 178s Rank 0: assembler memory usage: 162584 KiB 178s Date: Mon Jul 8 20:54:34 2024 178s Rank 0 is distributing fusions [1/1] (completed) 178s Rank 0 : VirtualCommunicator (service provided by BufferedData): 970 virtual messages generated 6 real messages (0.618557%) 178s Rank 0: assembler memory usage: 162584 KiB 178s Date: Mon Jul 8 20:54:34 2024 178s Rank 0 cycleNumber= 2 178s 178s *** 178s Step: Merging of redundant paths 178s Date: Mon Jul 8 20:54:34 2024 178s Elapsed time: 6 seconds 178s Since beginning: 23 seconds 178s *** 178s 178s 178s Rank 0 appended 1 elements 178s 178s *** 178s Step: Generation of contigs 178s Date: Mon Jul 8 20:54:34 2024 178s Elapsed time: 0 seconds 178s Since beginning: 23 seconds 178s *** 178s 178s Rank 0 objectName: 0 => peakCoverage: 237 blockSize: 970 178s Rank 0: gathering scaffold links [1/1] [970/970] (completed) 178s Rank 0 ineligibleObjects: 0/970 (0.00%) 178s Rank 0: assembler memory usage: 162584 KiB 178s contig: 0 vertices: 970 averageCoverage: 237 standardDeviation: 115 peakCoverage: 237 repeatCoverage: 474 178s Rank 0 finished gathering scaffold links. 178s Rank 0 will write 1 contig lengths 178s Rank 0 will solve the scaffolding problem. 178s Welcome to GreedySolver v1.0 178s 1 vertices; 0 edges 178s 1 contigs >= 500 178s Edges in solution: 0 178s 178s Conflict statistics: 178s 1 scaffolds, 1 >= 500 178s Total: 1000 nucleotides 178s 178s *** 178s Step: Scaffolding of contigs 178s Date: Mon Jul 8 20:54:34 2024 178s Elapsed time: 0 seconds 178s Since beginning: 23 seconds 178s *** 178s 178s Rank 0 syncing with master 178s 178s *** 178s Step: Counting sequences to search 178s Date: Mon Jul 8 20:54:34 2024 178s Elapsed time: 0 seconds 178s Since beginning: 23 seconds 178s *** 178s 178s 178s Rank 0 will add colors, 0 sequences in 0 files to process 178s Rank 0 : VirtualCommunicator (service provided by BufferedData): 0 virtual messages generated 0 real messages (0.00%) 179s 179s *** 179s Step: Graph coloring 179s Date: Mon Jul 8 20:54:35 2024 179s Elapsed time: 1 seconds 179s Since beginning: 24 seconds 179s *** 179s 179s 179s Rank 0: starting SlaveMode= call_RAY_SLAVE_MODE_CONTIG_BIOLOGICAL_ABUNDANCES 179s Rank 0 shares its counts 179s Rank 0 computing contig abundances [1/1] [1/970] 179s Rank 0 computing contig abundances [1/1] [970/970] 179s [IO] Input/output operations for coverage XML objects: 1 / bufferSize: 16777216 bytes 179s 179s *** 179s Step: Counting contig biological abundances 179s Date: Mon Jul 8 20:54:35 2024 179s Elapsed time: 0 seconds 179s Since beginning: 24 seconds 179s *** 179s 179s 179s Rank 0 colored the graph with 0 real colors using 1 virtual colors 179s Rank 0 : VirtualCommunicator (service provided by BufferedData): 3880 virtual messages generated 8 real messages (0.21%) 179s 179s *** 179s Step: Counting sequence biological abundances 179s Date: Mon Jul 8 20:54:35 2024 179s Elapsed time: 0 seconds 179s Since beginning: 24 seconds 179s *** 179s 179s 179s [IO] Input/output operations for sequence XML objects: 0 / bufferSize: 16777216 bytes 179s [IO] Input/output operations for identification TSV objects: 0 / bufferSize: 16777216 bytes 180s Rank 0 has exactly 0 k-mer physical colors for the phylogeny. 180s 180s [TaxonomyViewer::copyTaxonsFromSecondaryTable] 0 -> 0 180s Rank 0 is starting taxon syncing across the compute tribe. 180s 180s *** 180s Step: Loading taxons 180s Date: Mon Jul 8 20:54:36 2024 180s Elapsed time: 1 seconds 180s Since beginning: 25 seconds 180s *** 180s 180s Rank 0 synced taxons across the grid with 1 poor slaves. 180s [TaxonomyViewer::copyTaxonsFromSecondaryTable] 0 -> 0 180s Rank 0 has 0 taxons after syncing with master 181s 181s 181s *** 181s Step: Loading tree 181s Date: Mon Jul 8 20:54:37 2024 181s Elapsed time: 1 seconds 181s Since beginning: 26 seconds 181s *** 181s 183s Rank 0 has exactly 0 k-mer physical colors related to EMBL CDS objects. 183s 183s Rank 0: counting ontology terms in the graph... 184s Rank 0: 0 have some biological signal 184s Number of dereferenced alternate handles: 0 184s Number of k-mer observations with gene ontology terms: 0 184s Rank 0: synced ontology term profiles with master 184s Rank 0: synchronization is complete! 184s Rank 0: ontology terms with biological signal: 0 184s Populated recursive values... 184s Gene ontology terms without depth information: 0 184s [GeneOntology] maximum depth for GeneOntologyDomain  is 0 184s [GeneOntology] maximum depth for GeneOntologyDomain [GeneOntology] maximum depth for GeneOntologyDomain  is 0 184s 184s *** 184s Step: Processing gene ontologies 184s Date: Mon Jul 8 20:54:40 2024 184s Elapsed time: 3 seconds 184s Since beginning: 29 seconds 184s *** 184s 184s Rank 0: the CorePlugin GenomeNeighbourhood is disabled... 184s [GenomeNeighbourhood] in final list: 0 184s 184s *** 184s Step: Computing neighbourhoods 184s Date: Mon Jul 8 20:54:40 2024 184s Elapsed time: 0 seconds 184s Since beginning: 29 seconds 184s *** 184s 184s Contigs >= 100 nt 184s Number: 1 184s Total length: 1000 184s Average: 1000 184s N50: 1000 184s Median: 1000 184s Largest: 1000 184s Contigs >= 500 nt 184s Number: 1 184s Total length: 1000 184s Average: 1000 184s N50: 1000 184s Median: 1000 184s Largest: 1000 184s Scaffolds >= 100 nt 184s Number: 1 184s Total length: 1000 184s Average: 1000 184s N50: 1000 184s Median: 1000 184s Largest: 1000 184s Scaffolds >= 500 nt 184s Number: 1 184s Total length: 1000 184s Average: 1000 184s N50: 1000 184s Median: 1000 184s Largest: 1000 184s 184s Rank 0 wrote test1/Contigs.fasta 184s Rank 0 wrote test1/Scaffolds.fasta 184s Check for test1/* 184s 184s 184s 184s ************************************************** 184s This program comes with ABSOLUTELY NO WARRANTY. 184s This is free software, and you are welcome to redistribute it 184s under certain conditions; see "LICENSE.txt" for details. 184s ************************************************** 184s 184s Ray Copyright (C) 2010, 2011, 2012, 2013 Sébastien Boisvert 184s Centre de recherche en infectiologie de l'Université Laval 184s Project funded by the Canadian Institutes of Health Research (Doctoral award 200902CGM-204212-172830 to S.B.) 184s http://denovoassembler.sf.net/ 184s 184s References to cite: 184s 184s Sébastien Boisvert, Frédéric Raymond, Élénie Godzaridis, François Laviolette and Jacques Corbeil. 184s Ray Meta: scalable de novo metagenome assembly and profiling. 184s Genome Biology (BioMed Central Ltd). 184s 13:R122, Published: 22 December 2012 184s http://dx.doi.org/doi:10.1186/gb-2012-13-12-r122 184s 184s Sébastien Boisvert, François Laviolette & Jacques Corbeil. 184s Ray: simultaneous assembly of reads from a mix of high-throughput sequencing technologies. 184s Journal of Computational Biology (Mary Ann Liebert, Inc. publishers, New York, U.S.A.). 184s November 2010, Volume 17, Issue 11, Pages 1519-1533. 184s http://dx.doi.org/doi:10.1089/cmb.2009.0238 184s 184s Ray version 2.3.1 184s License for Ray: GNU General Public License version 3 184s RayPlatform version: 2.0.1 184s License for RayPlatform: GNU Lesser General Public License version 3 184s 184s MAXKMERLENGTH: 32 184s Maximum coverage depth stored by CoverageDepth: 4294967295 184s MAXIMUM_MESSAGE_SIZE_IN_BYTES: 4000 bytes 184s FORCE_PACKING = n 184s ASSERT = n 184s HAVE_LIBZ = y 184s HAVE_LIBBZ2 = y 184s PROFILER_COLLECT = n 184s MINIRANKS = y 184s CLOCK_GETTIME = n 184s __linux__ = y 184s _MSC_VER = n 184s __GNUC__ = y 184s RAY_32_BITS = n 184s RAY_64_BITS = y 184s MPI standard version: MPI 3.1 184s MPI library: Open-MPI 4.1.6 184s Compiler: GNU gcc/g++ 13.2.0 184s MPI I/O: n 184s 184s 184s -k (to set the k-mer size) 184s Value: 31 184s 184s 184s Paired library # 0 184s -p (paired-end sequences) 184s Left sequences: SampleDirectory/s_6.first1000_1.fastq 184s Right sequences: SampleDirectory/s_6.first1000_2.fastq 184s Average length: automatic detection 184s Standard deviation: automatic detection 184s 184s Ray command: 184s mpiexec -n 1 Ray \ 184s -k \ 184s 31 \ 184s -detect-sequence-files \ 184s SampleDirectory \ 184s -o \ 184s test2 184s 184s Rank 0 wrote test2/RayCommand.txt 184s 184s k-mer length: 31 184s Rank 0: assembler memory usage: 41948 KiB 184s Rank 0: assembler memory usage: 107620 KiB 184s Rank 0: Rank= 0 Size= 1 ProcessIdentifier= 2921 184s Rank 0: testing the network, please wait... 184s 184s Rank 0 is testing the network [0/1000] 184s Rank 0 is testing the network [1000/1000] 184s Rank 0: mode round trip latency when requesting a reply for a message of 4000 bytes is 1 microseconds (10^-6 seconds) 184s Rank 0: average round trip latency when requesting a reply for a message of 4000 bytes is 1 microseconds (10^-6 seconds) 184s 184s Rank 0 wrote test2/NetworkTest.txt 184s 184s 184s *** 184s Step: Network testing 184s Date: Mon Jul 8 20:54:40 2024 184s Elapsed time: 0 seconds 184s Since beginning: 0 seconds 184s *** 184s 184s 184s Rank 0 is fetching file SampleDirectory/s_6.first1000_1.fastq with lazy loading (please wait...) 184s Rank 0: File SampleDirectory/s_6.first1000_1.fastq (Number 0) has 2054 sequences 184s Rank 0 is fetching file SampleDirectory/s_6.first1000_2.fastq with lazy loading (please wait...) 184s Rank 0: File SampleDirectory/s_6.first1000_2.fastq (Number 1) has 2054 sequences 184s Rank 0 wrote test2/NumberOfSequences.txt 184s Rank 0 wrote test2/SequencePartition.txt 184s 184s *** 184s Step: Counting sequences to assemble 184s Date: Mon Jul 8 20:54:40 2024 184s Elapsed time: 0 seconds 184s Since beginning: 0 seconds 184s *** 184s 184s 184s Rank 0 is loading sequence reads 184s Rank 0 : partition is [0;4107], 4108 sequence reads 184s Rank 0 is fetching file SampleDirectory/s_6.first1000_1.fastq with lazy loading (please wait...) 184s Rank 0 has 0 sequence reads 184s Rank 0: assembler memory usage: 120624 KiB 184s Rank 0 is fetching file SampleDirectory/s_6.first1000_2.fastq with lazy loading (please wait...) 184s Rank 0 has 4108 sequence reads (completed) 184s 184s *** 184s Step: Sequence loading 184s Date: Mon Jul 8 20:54:40 2024 184s Elapsed time: 0 seconds 184s Since beginning: 0 seconds 184s *** 184s 184s 184s [BloomFilter] allocated 254696 bytes for table with 2037568 bits 184s Rank 0 created its Bloom filter 184s Rank 0 is counting k-mers in sequence reads [1/4108] 184s Rank 0 is counting k-mers in sequence reads [4108/4108] (completed) 184s Rank 0 : VirtualCommunicator (service provided by BufferedData): 230710 virtual messages generated 462 real messages (0.200251%) 184s 184s 184s *** 184s Step: K-mer counting 184s Date: Mon Jul 8 20:54:40 2024 184s Elapsed time: 0 seconds 184s Since beginning: 0 seconds 184s *** 184s 184s 184s Rank 0 number of set bits in the Bloom filter: [ 7801 / 2037568 ] (0.382858%) 184s Rank 0 destroyed its Bloom filter 184s Rank 0 has 1954 k-mers (completed) 184s [BloomFilter] Rank 0: k-mers sampled -> 1954, k-mers dropped -> 0 (0%), k-mers accepted -> 1954 (100%) 184s Rank 0: assembler memory usage: 117016 KiB 185s 185s 185s Rank 0: the minimum coverage is 3 185s Rank 0: the peak coverage is 3 185s Warning: no peak observed in the k-mer coverage distribution. 185s to deal with the sequencing error rate, try to lower the k-mer length (-k) 185s If you are using RNA-Seq or metagenomic data, then you can ignore this warning. 185s 185s *** 185s Step: Coverage distribution analysis 185s Date: Mon Jul 8 20:54:41 2024 185s Elapsed time: 1 seconds 185s Since beginning: 1 seconds 185s *** 185s 185s 185s 186s Rank 0 is adding edges [1/4108] 186s Rank 0 is adding edges [4108/4108] (completed) 186s Rank 0 : VirtualCommunicator (service provided by BufferedData): 453238 virtual messages generated 1813 real messages (0.400011%) 186s Rank 0 : VirtualCommunicator (service provided by BufferedData): 453238 virtual messages generated 1813 real messages (0.400011%) 186s 186s *** 186s Step: Graph construction 186s Date: Mon Jul 8 20:54:42 2024 186s Elapsed time: 1 seconds 186s Since beginning: 2 seconds 186s *** 186s 186s 186s Rank 0 has 1954 vertices (completed) 186s Rank 0: assembler memory usage: 117016 KiB 187s Rank 0 is purging edges [1/1954] 187s Rank 0 is purging edges [1954/1954] (completed) 187s Rank 0: assembler memory usage: 117544 KiB 187s VirtualProcessor: completed jobs: 1954 187s Rank 0 : VirtualCommunicator (service provided by VirtualCommunicator): 3904 virtual messages generated 11 real messages (0.281762%) 188s Rank 0 wrote test2/degreeDistribution.txt 188s 188s *** 188s Step: Null edge purging 188s Date: Mon Jul 8 20:54:44 2024 188s Elapsed time: 2 seconds 188s Since beginning: 4 seconds 188s *** 188s 188s 188s Rank 0 is selecting optimal read markers [1/4108] 188s Rank 0: assembler memory usage: 117544 KiB 188s Rank 0 is selecting optimal read markers [4108/4108] (completed) 188s Rank 0: peak number of workers: 599, maximum: 32768 188s Rank 0 : VirtualCommunicator (service provided by VirtualCommunicator): 238890 virtual messages generated 609 real messages (0.254929%) 188s Rank 0: assembler memory usage: 125680 KiB 188s Rank 0: Freeing unused assembler memory: 4096 KiB freed 188s Rank 0: assembler memory usage: 125680 KiB 188s 188s *** 188s Step: Selection of optimal read markers 188s Date: Mon Jul 8 20:54:44 2024 188s Elapsed time: 0 seconds 188s Since beginning: 4 seconds 188s *** 188s 188s 188s Rank 0: memory usage for optimal read markers= 4096 KiB 188s Rank 0 is creating seeds [1/1954] 188s Rank 0: assembler memory usage: 125680 KiB 189s Rank 0 has 1 seeds 189s Rank 0 is creating seeds [1954/1954] (completed) 189s Rank 0: peak number of workers: 746, maximum: 32768 189s Rank 0 : VirtualCommunicator (service provided by VirtualCommunicator): 13612 virtual messages generated 1720 real messages (12.6359%) 189s Rank 0 runtime statistics for seeding algorithm: 189s Rank 0 Skipped paths because of dead end for head: 0 189s Rank 0 Skipped paths because of dead end for tail: 0 189s Rank 0 Skipped paths because of two dead ends: 0 189s Rank 0 Skipped paths because of bubble weak component: 0 189s Rank 0 Skipped paths because of short length: 1952 189s Rank 0 Skipped paths because of bad ownership: 1 189s Rank 0 Skipped paths because of low coverage: 0 189s Rank 0 Eligible paths: 1 189s Rank 0: assembler memory usage: 125680 KiB 190s Rank 0 has 1 seeds to register. 190s Rank 0 registered 0/1 190s Rank 0 registered 0/1 190s Rank 0 registered its seeds 190s VirtualProcessor: completed jobs: 0 190s Rank 0 : VirtualCommunicator (service provided by VirtualCommunicator): 0 virtual messages generated 0 real messages (0%) 191s Rank 0 freed 4194304 bytes from the path memory pool (chunks: 1) 201s Rank 0: gossiping generated 0 messages (gossips: 0 ---> 0) 201s Rank 0 merged its seeds: 1 seeds -> 1 seeds 201s 201s *** 201s Step: Detection of assembly seeds 201s Date: Mon Jul 8 20:54:57 2024 201s Elapsed time: 13 seconds 201s Since beginning: 17 seconds 201s *** 201s 201s 201s Rank 0 is calculating library lengths [1/1] 201s Rank 0 detected 1737 library lengths 201s Rank 0 is calculating library lengths [1/1] (completed) 201s Rank 0: peak number of workers: 1, maximum: 32768 201s Rank 0 : VirtualCommunicator (service provided by VirtualCommunicator): 7997 virtual messages generated 7997 real messages (100%) 201s Rank 0: assembler memory usage: 162548 KiB 201s Rank 0 : VirtualCommunicator (service provided by BufferedData): 67 virtual messages generated 1 real messages (1.49254%) 201s 201s Mode= 2 signalAverage= 9 201s CURRENT IS NOISE, 244 201s GOT HIT 212 201s 201s 201s Library # 0 (Automatic) -> average length: 214 and standard deviation: 10 201s 201s *** 201s Step: Estimation of outer distances for paired reads 201s Date: Mon Jul 8 20:54:57 2024 201s Elapsed time: 0 seconds 201s Since beginning: 17 seconds 201s *** 201s 201s 201s Rank 0 starts on seed 0, length is 845, flow 0 [0/1] 201s Rank 0 traversed 1000 nucleotide symbols 201s Rank 0: assembler memory usage: 166644 KiB 201s Rank 0 is extending seeds [1/1] (completed) 201s Rank 0 extended 1 seeds out of 1 (100.00%) 201s Rank 0: assembler memory usage: 158452 KiB 201s Rank 0 starting fusions 201s 201s *** 201s Step: Bidirectional extension of seeds 201s Date: Mon Jul 8 20:54:57 2024 201s Elapsed time: 0 seconds 201s Since beginning: 17 seconds 201s *** 201s 201s 201s Rank 0: starting clear step. cycleNumber= 0 202s Rank 0 adding 0 new fusions 202s Rank 0 cleared, 1 paths 202s Rank 0: starting distribution step 202s Rank 0 is distributing fusions [1/1] 202s Rank 0: assembler memory usage: 158452 KiB 202s Date: Mon Jul 8 20:54:58 2024 202s Rank 0 is distributing fusions [1/1] (completed) 202s Rank 0 : VirtualCommunicator (service provided by BufferedData): 970 virtual messages generated 6 real messages (0.618557%) 202s Rank 0: assembler memory usage: 162548 KiB 202s Date: Mon Jul 8 20:54:58 2024 202s Rank 0 tells others to compute fusions. 202s Rank 0 FusionTaskCreator assignNextTask [0/2] 202s Rank 0: assembler memory usage: 162548 KiB 202s Date: Mon Jul 8 20:54:58 2024 202s Rank 0 FusionTaskCreator processWorkerResult [0/2] 202s Rank 0: assembler memory usage: 162548 KiB 202s Date: Mon Jul 8 20:54:58 2024 202s Rank 0 FusionTaskCreator [2/2] 202s Statistics: all paths: 1 eliminated during fusing: 0 202s Rank 0: assembler memory usage: 162548 KiB 202s VirtualProcessor: completed jobs: 2 202s Rank 0 : VirtualCommunicator (service provided by VirtualCommunicator): 10907 virtual messages generated 10907 real messages (100%) 202s Rank 0: starting clear step. cycleNumber= 1 204s Rank 0 adding 0 new fusions 204s Rank 0 cleared, 1 paths 204s Rank 0 is distributing fusions [1/1] 204s Rank 0: assembler memory usage: 162548 KiB 204s Date: Mon Jul 8 20:55:00 2024 204s Rank 0 is distributing fusions [1/1] (completed) 204s Rank 0 : VirtualCommunicator (service provided by BufferedData): 970 virtual messages generated 6 real messages (0.618557%) 204s Rank 0: assembler memory usage: 162548 KiB 204s Date: Mon Jul 8 20:55:00 2024 204s Rank 0 JoinerTaskCreator assignNextTask [0/2] 204s Rank 0: assembler memory usage: 162548 KiB 204s Date: Mon Jul 8 20:55:00 2024 204s Rank 0 JoinerTaskCreator processWorkerResult [0/2] 204s Rank 0: assembler memory usage: 162548 KiB 204s Date: Mon Jul 8 20:55:00 2024 204s Rank 0 JoinerTaskCreator [2/2] 204s Statistics: all paths: 1 eliminated during joining: 0 204s Rank 0: assembler memory usage: 162548 KiB 204s Date: Mon Jul 8 20:55:00 2024 204s VirtualProcessor: completed jobs: 2 204s Rank 0 : VirtualCommunicator (service provided by VirtualCommunicator): 13817 virtual messages generated 13817 real messages (100%) 205s Rank 0 adding 0 new fusions 205s Rank 0 cleared, 1 paths 205s Rank 0: starting distribution step 205s Rank 0 is distributing fusions [1/1] 205s Rank 0: assembler memory usage: 162548 KiB 205s Date: Mon Jul 8 20:55:01 2024 205s Rank 0 is distributing fusions [1/1] (completed) 205s Rank 0 : VirtualCommunicator (service provided by BufferedData): 970 virtual messages generated 6 real messages (0.618557%) 205s Rank 0: assembler memory usage: 162548 KiB 205s Date: Mon Jul 8 20:55:01 2024 205s Rank 0 tells others to compute fusions. 205s Rank 0 FusionTaskCreator assignNextTask [0/2] 205s Rank 0: assembler memory usage: 162548 KiB 205s Date: Mon Jul 8 20:55:01 2024 205s Rank 0 FusionTaskCreator processWorkerResult [0/2] 205s Rank 0: assembler memory usage: 162548 KiB 205s Date: Mon Jul 8 20:55:01 2024 205s Rank 0 FusionTaskCreator [2/2] 205s Statistics: all paths: 1 eliminated during fusing: 0 205s Rank 0: assembler memory usage: 162548 KiB 205s VirtualProcessor: completed jobs: 2 205s Rank 0 : VirtualCommunicator (service provided by VirtualCommunicator): 16727 virtual messages generated 16727 real messages (100%) 205s Rank 0: starting clear step. cycleNumber= 2 206s Rank 0 adding 0 new fusions 206s Rank 0 cleared, 1 paths 206s Rank 0 is distributing fusions [1/1] 206s Rank 0: assembler memory usage: 162548 KiB 206s Date: Mon Jul 8 20:55:02 2024 206s Rank 0 is distributing fusions [1/1] (completed) 206s Rank 0 : VirtualCommunicator (service provided by BufferedData): 970 virtual messages generated 6 real messages (0.618557%) 206s Rank 0: assembler memory usage: 162548 KiB 206s Date: Mon Jul 8 20:55:02 2024 206s Rank 0 JoinerTaskCreator assignNextTask [0/2] 206s Rank 0: assembler memory usage: 162548 KiB 206s Date: Mon Jul 8 20:55:02 2024 206s Rank 0 JoinerTaskCreator processWorkerResult [0/2] 206s Rank 0: assembler memory usage: 162548 KiB 206s Date: Mon Jul 8 20:55:02 2024 206s Rank 0 JoinerTaskCreator [2/2] 206s Statistics: all paths: 1 eliminated during joining: 0 206s Rank 0: assembler memory usage: 162548 KiB 206s Date: Mon Jul 8 20:55:02 2024 206s VirtualProcessor: completed jobs: 2 206s Rank 0 : VirtualCommunicator (service provided by VirtualCommunicator): 19637 virtual messages generated 19637 real messages (100%) 207s Rank 0 adding 0 new fusions 207s Rank 0 cleared, 1 paths 207s Rank 0: starting distribution step 207s Rank 0 is distributing fusions [1/1] 207s Rank 0: assembler memory usage: 162548 KiB 207s Date: Mon Jul 8 20:55:03 2024 207s Rank 0 is distributing fusions [1/1] (completed) 207s Rank 0 : VirtualCommunicator (service provided by BufferedData): 970 virtual messages generated 6 real messages (0.618557%) 207s Rank 0: assembler memory usage: 162548 KiB 207s Date: Mon Jul 8 20:55:03 2024 207s Rank 0 cycleNumber= 2 207s 207s *** 207s Step: Merging of redundant paths 207s Date: Mon Jul 8 20:55:03 2024 207s Elapsed time: 6 seconds 207s Since beginning: 23 seconds 207s *** 207s 207s 207s Rank 0 appended 1 elements 207s 207s *** 207s Step: Generation of contigs 207s Date: Mon Jul 8 20:55:03 2024 207s Elapsed time: 0 seconds 207s Since beginning: 23 seconds 207s *** 207s 207s Rank 0 objectName: 0 => peakCoverage: 237 blockSize: 970 207s Rank 0: gathering scaffold links [1/1] [970/970] (completed) 207s Rank 0 ineligibleObjects: 0/970 (0.00%) 207s Rank 0: assembler memory usage: 162548 KiB 207s contig: 0 vertices: 970 averageCoverage: 237 standardDeviation: 115 peakCoverage: 237 repeatCoverage: 474 207s Rank 0 finished gathering scaffold links. 207s Rank 0 will write 1 contig lengths 207s Rank 0 will solve the scaffolding problem. 207s Welcome to GreedySolver v1.0 207s 1 vertices; 0 edges 207s 1 contigs >= 500 207s Edges in solution: 0 207s 207s Conflict statistics: 207s 1 scaffolds, 1 >= 500 207s Total: 1000 nucleotides 207s 207s *** 207s Step: Scaffolding of contigs 207s Date: Mon Jul 8 20:55:03 2024 207s Elapsed time: 0 seconds 207s Since beginning: 23 seconds 207s *** 207s 207s Rank 0 syncing with master 207s 207s *** 207s Step: Counting sequences to search 207s Date: Mon Jul 8 20:55:03 2024 207s Elapsed time: 0 seconds 207s Since beginning: 23 seconds 207s *** 207s 207s 207s Rank 0 will add colors, 0 sequences in 0 files to process 207s Rank 0 : VirtualCommunicator (service provided by BufferedData): 0 virtual messages generated 0 real messages (0.00%) 208s 208s *** 208s Step: Graph coloring 208s Date: Mon Jul 8 20:55:04 2024 208s Elapsed time: 1 seconds 208s Since beginning: 24 seconds 208s *** 208s 208s 208s Rank 0: starting SlaveMode= call_RAY_SLAVE_MODE_CONTIG_BIOLOGICAL_ABUNDANCES 208s Rank 0 shares its counts 208s Rank 0 computing contig abundances [1/1] [1/970] 208s Rank 0 computing contig abundances [1/1] [970/970] 208s [IO] Input/output operations for coverage XML objects: 1 / bufferSize: 16777216 bytes 208s 208s *** 208s Step: Counting contig biological abundances 208s Date: Mon Jul 8 20:55:04 2024 208s Elapsed time: 0 seconds 208s Since beginning: 24 seconds 208s *** 208s 208s 208s Rank 0 colored the graph with 0 real colors using 1 virtual colors 208s Rank 0 : VirtualCommunicator (service provided by BufferedData): 3880 virtual messages generated 8 real messages (0.21%) 208s 208s *** 208s Step: Counting sequence biological abundances 208s Date: Mon Jul 8 20:55:04 2024 208s Elapsed time: 0 seconds 208s Since beginning: 24 seconds 208s *** 208s 208s 208s [IO] Input/output operations for sequence XML objects: 0 / bufferSize: 16777216 bytes 208s [IO] Input/output operations for identification TSV objects: 0 / bufferSize: 16777216 bytes 209s Rank 0 has exactly 0 k-mer physical colors for the phylogeny. 209s 209s [TaxonomyViewer::copyTaxonsFromSecondaryTable] 0 -> 0 209s Rank 0 is starting taxon syncing across the compute tribe. 209s 209s *** 209s Step: Loading taxons 209s Date: Mon Jul 8 20:55:05 2024 209s Elapsed time: 1 seconds 209s Since beginning: 25 seconds 209s *** 209s 209s Rank 0 synced taxons across the grid with 1 poor slaves. 209s [TaxonomyViewer::copyTaxonsFromSecondaryTable] 0 -> 0 209s Rank 0 has 0 taxons after syncing with master 210s 210s 210s *** 210s Step: Loading tree 210s Date: Mon Jul 8 20:55:06 2024 210s Elapsed time: 1 seconds 210s Since beginning: 26 seconds 210s *** 210s 212s Rank 0 has exactly 0 k-mer physical colors related to EMBL CDS objects. 212s 212s Rank 0: counting ontology terms in the graph... 213s Rank 0: 0 have some biological signal 213s Number of dereferenced alternate handles: 0 213s Number of k-mer observations with gene ontology terms: 0 213s Rank 0: synced ontology term profiles with master 213s Rank 0: synchronization is complete! 213s Rank 0: ontology terms with biological signal: 0 213s Populated recursive values... 213s Gene ontology terms without depth information: 0 213s [GeneOntology] maximum depth for GeneOntologyDomain  is 0 213s [GeneOntology] maximum depth for GeneOntologyDomain [GeneOntology] maximum depth for GeneOntologyDomain  is 0 213s 213s *** 213s Step: Processing gene ontologies 213s Date: Mon Jul 8 20:55:09 2024 213s Elapsed time: 3 seconds 213s Since beginning: 29 seconds 213s *** 213s 213s Rank 0: the CorePlugin GenomeNeighbourhood is disabled... 213s [GenomeNeighbourhood] in final list: 0 213s 213s *** 213s Step: Computing neighbourhoods 213s Date: Mon Jul 8 20:55:09 2024 213s Elapsed time: 0 seconds 213s Since beginning: 29 seconds 213s *** 213s 213s Contigs >= 100 nt 213s Number: 1 213s Total length: 1000 213s Average: 1000 213s N50: 1000 213s Median: 1000 213s Largest: 1000 213s Contigs >= 500 nt 213s Number: 1 213s Total length: 1000 213s Average: 1000 213s N50: 1000 213s Median: 1000 213s Largest: 1000 213s Scaffolds >= 100 nt 213s Number: 1 213s Total length: 1000 213s Average: 1000 213s N50: 1000 213s Median: 1000 213s Largest: 1000 213s Scaffolds >= 500 nt 213s Number: 1 213s Total length: 1000 213s Average: 1000 213s N50: 1000 213s Median: 1000 213s Largest: 1000 213s 213s Rank 0 wrote test2/Contigs.fasta 213s Rank 0 wrote test2/Scaffolds.fasta 213s Check for test2/* 213s 213s 213s 213s ************************************************** 213s This program comes with ABSOLUTELY NO WARRANTY. 213s This is free software, and you are welcome to redistribute it 213s under certain conditions; see "LICENSE.txt" for details. 213s ************************************************** 213s 213s Ray Copyright (C) 2010, 2011, 2012, 2013 Sébastien Boisvert 213s Centre de recherche en infectiologie de l'Université Laval 213s Project funded by the Canadian Institutes of Health Research (Doctoral award 200902CGM-204212-172830 to S.B.) 213s http://denovoassembler.sf.net/ 213s 213s References to cite: 213s 213s Sébastien Boisvert, Frédéric Raymond, Élénie Godzaridis, François Laviolette and Jacques Corbeil. 213s Ray Meta: scalable de novo metagenome assembly and profiling. 213s Genome Biology (BioMed Central Ltd). 213s 13:R122, Published: 22 December 2012 213s http://dx.doi.org/doi:10.1186/gb-2012-13-12-r122 213s 213s Sébastien Boisvert, François Laviolette & Jacques Corbeil. 213s Ray: simultaneous assembly of reads from a mix of high-throughput sequencing technologies. 213s Journal of Computational Biology (Mary Ann Liebert, Inc. publishers, New York, U.S.A.). 213s November 2010, Volume 17, Issue 11, Pages 1519-1533. 213s http://dx.doi.org/doi:10.1089/cmb.2009.0238 213s 213s Ray version 2.3.1 213s License for Ray: GNU General Public License version 3 213s RayPlatform version: 2.0.1 213s License for RayPlatform: GNU Lesser General Public License version 3 213s 213s MAXKMERLENGTH: 32 213s Maximum coverage depth stored by CoverageDepth: 4294967295 213s MAXIMUM_MESSAGE_SIZE_IN_BYTES: 4000 bytes 213s FORCE_PACKING = n 213s ASSERT = n 213s HAVE_LIBZ = y 213s HAVE_LIBBZ2 = y 213s PROFILER_COLLECT = n 213s MINIRANKS = y 213s CLOCK_GETTIME = n 213s __linux__ = y 213s _MSC_VER = n 213s __GNUC__ = y 213s RAY_32_BITS = n 213s RAY_64_BITS = y 213s MPI standard version: MPI 3.1 213s MPI library: Open-MPI 4.1.6 213s Compiler: GNU gcc/g++ 13.2.0 213s MPI I/O: n 213s 213s 213s -k (to set the k-mer size) 213s Value: 29 213s 213s 213s Paired library # 0 213s -p (paired-end sequences) 213s Left sequences: SampleDirectory/s_6.first1000_1.fastq 213s Right sequences: SampleDirectory/s_6.first1000_2.fastq 213s Average length: automatic detection 213s Standard deviation: automatic detection 213s 213s Ray command: 213s mpiexec -n 1 Ray \ 213s -k \ 213s 29 \ 213s -desable-recycling \ 213s -p \ 213s SampleDirectory/s_6.first1000_1.fastq \ 213s SampleDirectory/s_6.first1000_2.fastq 213s 213s Rank 0 wrote RayOutput/RayCommand.txt 213s 213s k-mer length: 29 213s Rank 0: assembler memory usage: 41948 KiB 213s Rank 0: assembler memory usage: 107620 KiB 213s Rank 0: Rank= 0 Size= 1 ProcessIdentifier= 2930 213s Rank 0: testing the network, please wait... 213s 213s Rank 0 is testing the network [0/1000] 213s Rank 0 is testing the network [1000/1000] 213s Rank 0: mode round trip latency when requesting a reply for a message of 4000 bytes is 1 microseconds (10^-6 seconds) 213s Rank 0: average round trip latency when requesting a reply for a message of 4000 bytes is 1 microseconds (10^-6 seconds) 213s 213s Rank 0 wrote RayOutput/NetworkTest.txt 213s 213s 213s *** 213s Step: Network testing 213s Date: Mon Jul 8 20:55:09 2024 213s Elapsed time: 0 seconds 213s Since beginning: 0 seconds 213s *** 213s 213s 213s Rank 0 is fetching file SampleDirectory/s_6.first1000_1.fastq with lazy loading (please wait...) 213s Rank 0: File SampleDirectory/s_6.first1000_1.fastq (Number 0) has 2054 sequences 213s Rank 0 is fetching file SampleDirectory/s_6.first1000_2.fastq with lazy loading (please wait...) 213s Rank 0: File SampleDirectory/s_6.first1000_2.fastq (Number 1) has 2054 sequences 213s Rank 0 wrote RayOutput/NumberOfSequences.txt 213s Rank 0 wrote RayOutput/SequencePartition.txt 213s 213s *** 213s Step: Counting sequences to assemble 213s Date: Mon Jul 8 20:55:09 2024 213s Elapsed time: 0 seconds 213s Since beginning: 0 seconds 213s *** 213s 213s 213s Rank 0 is loading sequence reads 213s Rank 0 : partition is [0;4107], 4108 sequence reads 213s Rank 0 is fetching file SampleDirectory/s_6.first1000_1.fastq with lazy loading (please wait...) 213s Rank 0 has 0 sequence reads 213s Rank 0: assembler memory usage: 120628 KiB 213s Rank 0 is fetching file SampleDirectory/s_6.first1000_2.fastq with lazy loading (please wait...) 213s Rank 0 has 4108 sequence reads (completed) 213s 213s *** 213s Step: Sequence loading 213s Date: Mon Jul 8 20:55:09 2024 213s Elapsed time: 0 seconds 213s Since beginning: 0 seconds 213s *** 213s 213s 213s [BloomFilter] allocated 238264 bytes for table with 1906112 bits 213s Rank 0 created its Bloom filter 213s Rank 0 is counting k-mers in sequence reads [1/4108] 213s Rank 0 is counting k-mers in sequence reads [4108/4108] (completed) 213s Rank 0 : VirtualCommunicator (service provided by BufferedData): 238926 virtual messages generated 478 real messages (0.200062%) 213s 213s 213s *** 213s Step: K-mer counting 213s Date: Mon Jul 8 20:55:09 2024 213s Elapsed time: 0 seconds 213s Since beginning: 0 seconds 213s *** 213s 213s 213s Rank 0 number of set bits in the Bloom filter: [ 7820 / 1906112 ] (0.410259%) 213s Rank 0 destroyed its Bloom filter 213s Rank 0 has 1958 k-mers (completed) 213s [BloomFilter] Rank 0: k-mers sampled -> 1958, k-mers dropped -> 0 (0%), k-mers accepted -> 1958 (100%) 213s Rank 0: assembler memory usage: 117008 KiB 214s 214s 214s Rank 0: the minimum coverage is 3 214s Rank 0: the peak coverage is 3 214s Warning: no peak observed in the k-mer coverage distribution. 214s to deal with the sequencing error rate, try to lower the k-mer length (-k) 214s If you are using RNA-Seq or metagenomic data, then you can ignore this warning. 214s 214s *** 214s Step: Coverage distribution analysis 214s Date: Mon Jul 8 20:55:10 2024 214s Elapsed time: 1 seconds 214s Since beginning: 1 seconds 214s *** 214s 214s 214s 214s Rank 0 is adding edges [1/4108] 214s Rank 0 is adding edges [4108/4108] (completed) 214s Rank 0 : VirtualCommunicator (service provided by BufferedData): 469636 virtual messages generated 1879 real messages (0.400097%) 214s Rank 0 : VirtualCommunicator (service provided by BufferedData): 469636 virtual messages generated 1879 real messages (0.400097%) 214s 214s *** 214s Step: Graph construction 214s Date: Mon Jul 8 20:55:10 2024 214s Elapsed time: 0 seconds 214s Since beginning: 1 seconds 214s *** 214s 214s 214s Rank 0 has 1958 vertices (completed) 214s Rank 0: assembler memory usage: 117008 KiB 216s Rank 0 is purging edges [1/1958] 216s Rank 0 is purging edges [1958/1958] (completed) 216s Rank 0: assembler memory usage: 117540 KiB 216s VirtualProcessor: completed jobs: 1958 216s Rank 0 : VirtualCommunicator (service provided by VirtualCommunicator): 3912 virtual messages generated 12 real messages (0.306748%) 217s Rank 0 wrote RayOutput/degreeDistribution.txt 217s 217s *** 217s Step: Null edge purging 217s Date: Mon Jul 8 20:55:13 2024 217s Elapsed time: 3 seconds 217s Since beginning: 4 seconds 217s *** 217s 217s 217s Rank 0 is selecting optimal read markers [1/4108] 217s Rank 0: assembler memory usage: 117540 KiB 217s Rank 0 is selecting optimal read markers [4108/4108] (completed) 217s Rank 0: peak number of workers: 599, maximum: 32768 217s Rank 0 : VirtualCommunicator (service provided by VirtualCommunicator): 247142 virtual messages generated 624 real messages (0.252486%) 217s Rank 0: assembler memory usage: 125752 KiB 217s Rank 0: Freeing unused assembler memory: 4096 KiB freed 217s Rank 0: assembler memory usage: 125752 KiB 217s 217s *** 217s Step: Selection of optimal read markers 217s Date: Mon Jul 8 20:55:13 2024 217s Elapsed time: 0 seconds 217s Since beginning: 4 seconds 217s *** 217s 217s 217s Rank 0: memory usage for optimal read markers= 4096 KiB 217s Rank 0 is creating seeds [1/1958] 217s Rank 0: assembler memory usage: 125752 KiB 218s Rank 0 has 1 seeds 218s Rank 0 is creating seeds [1958/1958] (completed) 218s Rank 0: peak number of workers: 746, maximum: 32768 218s Rank 0 : VirtualCommunicator (service provided by VirtualCommunicator): 13640 virtual messages generated 1708 real messages (12.522%) 218s Rank 0 runtime statistics for seeding algorithm: 218s Rank 0 Skipped paths because of dead end for head: 0 218s Rank 0 Skipped paths because of dead end for tail: 0 218s Rank 0 Skipped paths because of two dead ends: 0 218s Rank 0 Skipped paths because of bubble weak component: 0 218s Rank 0 Skipped paths because of short length: 1956 218s Rank 0 Skipped paths because of bad ownership: 1 218s Rank 0 Skipped paths because of low coverage: 0 218s Rank 0 Eligible paths: 1 218s Rank 0: assembler memory usage: 125752 KiB 218s Rank 0 has 1 seeds to register. 218s Rank 0 registered 0/1 218s Rank 0 registered 0/1 218s Rank 0 registered its seeds 218s VirtualProcessor: completed jobs: 0 218s Rank 0 : VirtualCommunicator (service provided by VirtualCommunicator): 0 virtual messages generated 0 real messages (0%) 219s Rank 0 freed 4194304 bytes from the path memory pool (chunks: 1) 229s Rank 0: gossiping generated 0 messages (gossips: 0 ---> 0) 229s Rank 0 merged its seeds: 1 seeds -> 1 seeds 229s 229s *** 229s Step: Detection of assembly seeds 229s Date: Mon Jul 8 20:55:25 2024 229s Elapsed time: 12 seconds 229s Since beginning: 16 seconds 229s *** 229s 229s 229s Rank 0 is calculating library lengths [1/1] 229s Rank 0 detected 1743 library lengths 229s Rank 0 is calculating library lengths [1/1] (completed) 229s Rank 0: peak number of workers: 1, maximum: 32768 229s Rank 0 : VirtualCommunicator (service provided by VirtualCommunicator): 8005 virtual messages generated 8005 real messages (100%) 229s Rank 0: assembler memory usage: 162620 KiB 229s Rank 0 : VirtualCommunicator (service provided by BufferedData): 67 virtual messages generated 1 real messages (1.49254%) 229s 229s Mode= 2 signalAverage= 10 229s CURRENT IS NOISE, 244 229s GOT HIT 214 229s 229s 229s Library # 0 (Automatic) -> average length: 214 and standard deviation: 10 229s 229s *** 229s Step: Estimation of outer distances for paired reads 229s Date: Mon Jul 8 20:55:25 2024 229s Elapsed time: 0 seconds 229s Since beginning: 16 seconds 229s *** 229s 229s 229s Rank 0 starts on seed 0, length is 845, flow 0 [0/1] 229s Rank 0 traversed 1000 nucleotide symbols 229s Rank 0: assembler memory usage: 166716 KiB 229s Rank 0 is extending seeds [1/1] (completed) 229s Rank 0 extended 1 seeds out of 1 (100.00%) 229s Rank 0: assembler memory usage: 158524 KiB 229s Rank 0 starting fusions 229s 229s *** 229s Step: Bidirectional extension of seeds 229s Date: Mon Jul 8 20:55:25 2024 229s Elapsed time: 0 seconds 229s Since beginning: 16 seconds 229s *** 229s 229s 229s Rank 0: starting clear step. cycleNumber= 0 230s Rank 0 adding 0 new fusions 230s Rank 0 cleared, 1 paths 230s Rank 0: starting distribution step 230s Rank 0 is distributing fusions [1/1] 230s Rank 0: assembler memory usage: 158524 KiB 230s Date: Mon Jul 8 20:55:26 2024 230s Rank 0 is distributing fusions [1/1] (completed) 230s Rank 0 : VirtualCommunicator (service provided by BufferedData): 972 virtual messages generated 6 real messages (0.617284%) 230s Rank 0: assembler memory usage: 162620 KiB 230s Date: Mon Jul 8 20:55:26 2024 230s Rank 0 tells others to compute fusions. 230s Rank 0 FusionTaskCreator assignNextTask [0/2] 230s Rank 0: assembler memory usage: 162620 KiB 230s Date: Mon Jul 8 20:55:26 2024 231s Rank 0 FusionTaskCreator processWorkerResult [0/2] 231s Rank 0: assembler memory usage: 162620 KiB 231s Date: Mon Jul 8 20:55:26 2024 231s Rank 0 FusionTaskCreator [2/2] 231s Statistics: all paths: 1 eliminated during fusing: 0 231s Rank 0: assembler memory usage: 162620 KiB 231s VirtualProcessor: completed jobs: 2 231s Rank 0 : VirtualCommunicator (service provided by VirtualCommunicator): 10921 virtual messages generated 10921 real messages (100%) 231s Rank 0: starting clear step. cycleNumber= 1 232s Rank 0 adding 0 new fusions 232s Rank 0 cleared, 1 paths 232s Rank 0 is distributing fusions [1/1] 232s Rank 0: assembler memory usage: 162620 KiB 232s Date: Mon Jul 8 20:55:28 2024 232s Rank 0 is distributing fusions [1/1] (completed) 232s Rank 0 : VirtualCommunicator (service provided by BufferedData): 972 virtual messages generated 6 real messages (0.617284%) 232s Rank 0: assembler memory usage: 162620 KiB 232s Date: Mon Jul 8 20:55:28 2024 232s Rank 0 JoinerTaskCreator assignNextTask [0/2] 232s Rank 0: assembler memory usage: 162620 KiB 232s Date: Mon Jul 8 20:55:28 2024 232s Rank 0 JoinerTaskCreator processWorkerResult [0/2] 232s Rank 0: assembler memory usage: 162620 KiB 232s Date: Mon Jul 8 20:55:28 2024 232s Rank 0 JoinerTaskCreator [2/2] 232s Statistics: all paths: 1 eliminated during joining: 0 232s Rank 0: assembler memory usage: 162620 KiB 232s Date: Mon Jul 8 20:55:28 2024 232s VirtualProcessor: completed jobs: 2 232s Rank 0 : VirtualCommunicator (service provided by VirtualCommunicator): 13837 virtual messages generated 13837 real messages (100%) 233s Rank 0 adding 0 new fusions 233s Rank 0 cleared, 1 paths 233s Rank 0: starting distribution step 233s Rank 0 is distributing fusions [1/1] 233s Rank 0: assembler memory usage: 162620 KiB 233s Date: Mon Jul 8 20:55:29 2024 233s Rank 0 is distributing fusions [1/1] (completed) 233s Rank 0 : VirtualCommunicator (service provided by BufferedData): 972 virtual messages generated 6 real messages (0.617284%) 233s Rank 0: assembler memory usage: 162620 KiB 233s Date: Mon Jul 8 20:55:29 2024 233s Rank 0 tells others to compute fusions. 233s Rank 0 FusionTaskCreator assignNextTask [0/2] 233s Rank 0: assembler memory usage: 162620 KiB 233s Date: Mon Jul 8 20:55:29 2024 233s Rank 0 FusionTaskCreator processWorkerResult [0/2] 233s Rank 0: assembler memory usage: 162620 KiB 233s Date: Mon Jul 8 20:55:29 2024 233s Rank 0 FusionTaskCreator [2/2] 233s Statistics: all paths: 1 eliminated during fusing: 0 233s Rank 0: assembler memory usage: 162620 KiB 233s VirtualProcessor: completed jobs: 2 233s Rank 0 : VirtualCommunicator (service provided by VirtualCommunicator): 16753 virtual messages generated 16753 real messages (100%) 233s Rank 0: starting clear step. cycleNumber= 2 234s Rank 0 adding 0 new fusions 234s Rank 0 cleared, 1 paths 234s Rank 0 is distributing fusions [1/1] 234s Rank 0: assembler memory usage: 162620 KiB 234s Date: Mon Jul 8 20:55:30 2024 234s Rank 0 is distributing fusions [1/1] (completed) 234s Rank 0 : VirtualCommunicator (service provided by BufferedData): 972 virtual messages generated 6 real messages (0.617284%) 234s Rank 0: assembler memory usage: 162620 KiB 234s Date: Mon Jul 8 20:55:30 2024 234s Rank 0 JoinerTaskCreator assignNextTask [0/2] 234s Rank 0: assembler memory usage: 162620 KiB 234s Date: Mon Jul 8 20:55:30 2024 234s Rank 0 JoinerTaskCreator processWorkerResult [0/2] 234s Rank 0: assembler memory usage: 162620 KiB 234s Date: Mon Jul 8 20:55:30 2024 234s Rank 0 JoinerTaskCreator [2/2] 234s Statistics: all paths: 1 eliminated during joining: 0 234s Rank 0: assembler memory usage: 162620 KiB 234s Date: Mon Jul 8 20:55:30 2024 234s VirtualProcessor: completed jobs: 2 234s Rank 0 : VirtualCommunicator (service provided by VirtualCommunicator): 19669 virtual messages generated 19669 real messages (100%) 235s Rank 0 adding 0 new fusions 235s Rank 0 cleared, 1 paths 235s Rank 0: starting distribution step 235s Rank 0 is distributing fusions [1/1] 235s Rank 0: assembler memory usage: 162620 KiB 235s Date: Mon Jul 8 20:55:31 2024 235s Rank 0 is distributing fusions [1/1] (completed) 235s Rank 0 : VirtualCommunicator (service provided by BufferedData): 972 virtual messages generated 6 real messages (0.617284%) 235s Rank 0: assembler memory usage: 162620 KiB 235s Date: Mon Jul 8 20:55:31 2024 235s Rank 0 cycleNumber= 2 235s 235s *** 235s Step: Merging of redundant paths 235s Date: Mon Jul 8 20:55:31 2024 235s Elapsed time: 6 seconds 235s Since beginning: 22 seconds 235s *** 235s 235s 235s Rank 0 appended 1 elements 235s 235s *** 235s Step: Generation of contigs 235s Date: Mon Jul 8 20:55:31 2024 235s Elapsed time: 0 seconds 235s Since beginning: 22 seconds 235s *** 235s 235s Rank 0 objectName: 0 => peakCoverage: 245 blockSize: 972 235s Rank 0: gathering scaffold links [1/1] [972/972] (completed) 235s Rank 0 ineligibleObjects: 0/972 (0.00%) 235s Rank 0: assembler memory usage: 162620 KiB 235s contig: 0 vertices: 972 averageCoverage: 245 standardDeviation: 117 peakCoverage: 245 repeatCoverage: 490 235s Rank 0 finished gathering scaffold links. 235s Rank 0 will write 1 contig lengths 235s Rank 0 will solve the scaffolding problem. 235s Welcome to GreedySolver v1.0 235s 1 vertices; 0 edges 235s 1 contigs >= 500 235s Edges in solution: 0 235s 235s Conflict statistics: 235s 1 scaffolds, 1 >= 500 235s Total: 1000 nucleotides 235s 235s *** 235s Step: Scaffolding of contigs 235s Date: Mon Jul 8 20:55:31 2024 235s Elapsed time: 0 seconds 235s Since beginning: 22 seconds 235s *** 235s 235s Rank 0 syncing with master 235s 235s *** 235s Step: Counting sequences to search 235s Date: Mon Jul 8 20:55:31 2024 235s Elapsed time: 0 seconds 235s Since beginning: 22 seconds 235s *** 235s 235s 235s Rank 0 will add colors, 0 sequences in 0 files to process 235s Rank 0 : VirtualCommunicator (service provided by BufferedData): 0 virtual messages generated 0 real messages (0.00%) 236s 236s *** 236s Step: Graph coloring 236s Date: Mon Jul 8 20:55:32 2024 236s Elapsed time: 1 seconds 236s Since beginning: 23 seconds 236s *** 236s 236s 236s Rank 0: starting SlaveMode= call_RAY_SLAVE_MODE_CONTIG_BIOLOGICAL_ABUNDANCES 236s Rank 0 shares its counts 236s Rank 0 computing contig abundances [1/1] [1/972] 236s Rank 0 computing contig abundances [1/1] [972/972] 236s [IO] Input/output operations for coverage XML objects: 1 / bufferSize: 16777216 bytes 236s 236s *** 236s Step: Counting contig biological abundances 236s Date: Mon Jul 8 20:55:32 2024 236s Elapsed time: 0 seconds 236s Since beginning: 23 seconds 236s *** 236s 236s 236s Rank 0 colored the graph with 0 real colors using 1 virtual colors 236s Rank 0 : VirtualCommunicator (service provided by BufferedData): 3888 virtual messages generated 8 real messages (0.21%) 236s 236s *** 236s Step: Counting sequence biological abundances 236s Date: Mon Jul 8 20:55:32 2024 236s Elapsed time: 0 seconds 236s Since beginning: 23 seconds 236s *** 236s 236s 236s [IO] Input/output operations for sequence XML objects: 0 / bufferSize: 16777216 bytes 236s [IO] Input/output operations for identification TSV objects: 0 / bufferSize: 16777216 bytes 238s Rank 0 has exactly 0 k-mer physical colors for the phylogeny. 238s 238s [TaxonomyViewer::copyTaxonsFromSecondaryTable] 0 -> 0 238s Rank 0 is starting taxon syncing across the compute tribe. 238s 238s *** 238s Step: Loading taxons 238s Date: Mon Jul 8 20:55:33 2024 238s Elapsed time: 1 seconds 238s Since beginning: 24 seconds 238s *** 238s 238s Rank 0 synced taxons across the grid with 1 poor slaves. 238s [TaxonomyViewer::copyTaxonsFromSecondaryTable] 0 -> 0 238s Rank 0 has 0 taxons after syncing with master 239s 239s 239s *** 239s Step: Loading tree 239s Date: Mon Jul 8 20:55:35 2024 239s Elapsed time: 2 seconds 239s Since beginning: 26 seconds 239s *** 239s 240s Rank 0 has exactly 0 k-mer physical colors related to EMBL CDS objects. 240s 240s Rank 0: counting ontology terms in the graph... 241s Rank 0: 0 have some biological signal 241s Number of dereferenced alternate handles: 0 241s Number of k-mer observations with gene ontology terms: 0 241s Rank 0: synced ontology term profiles with master 241s Rank 0: synchronization is complete! 241s Rank 0: ontology terms with biological signal: 0 241s Populated recursive values... 241s Gene ontology terms without depth information: 0 241s [GeneOntology] maximum depth for GeneOntologyDomain  is 0 241s [GeneOntology] maximum depth for GeneOntologyDomain [GeneOntology] maximum depth for GeneOntologyDomain  is 0 241s 241s *** 241s Step: Processing gene ontologies 241s Date: Mon Jul 8 20:55:37 2024 241s Elapsed time: 2 seconds 241s Since beginning: 28 seconds 241s *** 241s 241s Rank 0: the CorePlugin GenomeNeighbourhood is disabled... 241s [GenomeNeighbourhood] in final list: 0 241s 241s *** 241s Step: Computing neighbourhoods 241s Date: Mon Jul 8 20:55:37 2024 241s Elapsed time: 0 seconds 241s Since beginning: 28 seconds 241s *** 241s 241s Contigs >= 100 nt 241s Number: 1 241s Total length: 1000 241s Average: 1000 241s N50: 1000 241s Median: 1000 241s Largest: 1000 241s Contigs >= 500 nt 241s Number: 1 241s Total length: 1000 241s Average: 1000 241s N50: 1000 241s Median: 1000 241s Largest: 1000 241s Scaffolds >= 100 nt 241s Number: 1 241s Total length: 1000 241s Average: 1000 241s N50: 1000 241s Median: 1000 241s Largest: 1000 241s Scaffolds >= 500 nt 241s Number: 1 241s Total length: 1000 241s Average: 1000 241s N50: 1000 241s Median: 1000 241s Largest: 1000 241s 241s Rank 0 wrote RayOutput/Contigs.fasta 241s Rank 0 wrote RayOutput/Scaffolds.fasta 241s Check for RayOutput/* 241s 241s 241s 241s ************************************************** 241s This program comes with ABSOLUTELY NO WARRANTY. 241s This is free software, and you are welcome to redistribute it 241s under certain conditions; see "LICENSE.txt" for details. 241s ************************************************** 241s 241s Ray Copyright (C) 2010, 2011, 2012, 2013 Sébastien Boisvert 241s Centre de recherche en infectiologie de l'Université Laval 241s Project funded by the Canadian Institutes of Health Research (Doctoral award 200902CGM-204212-172830 to S.B.) 241s http://denovoassembler.sf.net/ 241s 241s References to cite: 241s 241s Sébastien Boisvert, Frédéric Raymond, Élénie Godzaridis, François Laviolette and Jacques Corbeil. 241s Ray Meta: scalable de novo metagenome assembly and profiling. 241s Genome Biology (BioMed Central Ltd). 241s 13:R122, Published: 22 December 2012 241s http://dx.doi.org/doi:10.1186/gb-2012-13-12-r122 241s 241s Sébastien Boisvert, François Laviolette & Jacques Corbeil. 241s Ray: simultaneous assembly of reads from a mix of high-throughput sequencing technologies. 241s Journal of Computational Biology (Mary Ann Liebert, Inc. publishers, New York, U.S.A.). 241s November 2010, Volume 17, Issue 11, Pages 1519-1533. 241s http://dx.doi.org/doi:10.1089/cmb.2009.0238 241s 241s Ray version 2.3.1 241s License for Ray: GNU General Public License version 3 241s RayPlatform version: 2.0.1 241s License for RayPlatform: GNU Lesser General Public License version 3 241s 241s MAXKMERLENGTH: 32 241s Maximum coverage depth stored by CoverageDepth: 4294967295 241s MAXIMUM_MESSAGE_SIZE_IN_BYTES: 4000 bytes 241s FORCE_PACKING = n 241s ASSERT = n 241s HAVE_LIBZ = y 241s HAVE_LIBBZ2 = y 241s PROFILER_COLLECT = n 241s MINIRANKS = y 241s CLOCK_GETTIME = n 241s __linux__ = y 241s _MSC_VER = n 241s __GNUC__ = y 241s RAY_32_BITS = n 241s RAY_64_BITS = y 241s MPI standard version: MPI 3.1 241s MPI library: Open-MPI 4.1.6 241s Compiler: GNU gcc/g++ 13.2.0 241s MPI I/O: n 241s 241s 241s -k (to set the k-mer size) 241s Value: 31 241s 241s 241s Paired library # 0 241s -p (paired-end sequences) 241s Left sequences: ecoli_1K_1.fq 241s Right sequences: ecoli_1K_2.fq 241s Average length: automatic detection 241s Standard deviation: automatic detection 241s 241s Ray command: 241s mpiexec -n 2 Ray \ 241s -k \ 241s 31 \ 241s -p \ 241s ecoli_1K_1.fq \ 241s ecoli_1K_2.fq \ 241s -o \ 241s test3 241s 241s Rank 0 wrote test3/RayCommand.txt 241s 241s k-mer length: 31 241s Rank 0: assembler memory usage: 41948 KiB 241s Rank 1: assembler memory usage: 41948 KiB 241s Rank 1: assembler memory usage: 107760 KiB 241s Rank 1: Rank= 1 Size= 2 ProcessIdentifier= 2940 241s Rank 0: assembler memory usage: 107768 KiB 241s Rank 0: Rank= 0 Size= 2 ProcessIdentifier= 2939 241s Rank 0: testing the network, please wait... 241s 241s Rank 0 is testing the network [0/1000] 241s Rank 1 is testing the network [0/1000] 241s Rank 1 is testing the network [1000/1000] 241s Rank 1: mode round trip latency when requesting a reply for a message of 4000 bytes is 2 microseconds (10^-6 seconds) 241s Rank 1: average round trip latency when requesting a reply for a message of 4000 bytes is 5 microseconds (10^-6 seconds) 241s Rank 0 is testing the network [1000/1000] 241s Rank 0: mode round trip latency when requesting a reply for a message of 4000 bytes is 2 microseconds (10^-6 seconds) 241s Rank 0: average round trip latency when requesting a reply for a message of 4000 bytes is 5 microseconds (10^-6 seconds) 241s 241s Rank 0 wrote test3/NetworkTest.txt 241s 241s 241s *** 241s Step: Network testing 241s Date: Mon Jul 8 20:55:37 2024 241s Elapsed time: 0 seconds 241s Since beginning: 0 seconds 241s *** 241s 241s 241s Rank 0 is fetching file ecoli_1K_1.fq with lazy loading (please wait...) 241s Rank 1 is fetching file ecoli_1K_2.fq with lazy loading (please wait...) 241s Rank 0: File ecoli_1K_1.fq (Number 0) has 2054 sequences 241s Rank 1: File ecoli_1K_2.fq (Number 1) has 2054 sequences 241s Rank 0 wrote test3/NumberOfSequences.txt 241s Rank 0 wrote test3/SequencePartition.txt 241s 241s *** 241s Step: Counting sequences to assemble 241s Date: Mon Jul 8 20:55:37 2024 241s Elapsed time: 0 seconds 241s Since beginning: 0 seconds 241s *** 241s 241s 241s Rank 0 is loading sequence reads 241s Rank 1 is loading sequence reads 241s Rank 0 : partition is [0;2053], 2054 sequence reads 241s Rank 1 : partition is [2054;4107], 2054 sequence reads 241s Rank 0 is fetching file ecoli_1K_1.fq with lazy loading (please wait...) 241s Rank 1 is fetching file ecoli_1K_2.fq with lazy loading (please wait...) 241s Rank 1 has 0 sequence reads 241s Rank 0 has 0 sequence reads 241s Rank 0: assembler memory usage: 116568 KiB 241s Rank 0 has 2054 sequence reads (completed) 241s Rank 1: assembler memory usage: 116552 KiB 241s Rank 1 has 2054 sequence reads (completed) 241s 241s *** 241s Step: Sequence loading 241s Date: Mon Jul 8 20:55:37 2024 241s Elapsed time: 0 seconds 241s Since beginning: 0 seconds 241s *** 241s 241s 241s [BloomFilter] allocated 127352 bytes for table with 1018784 bits 241s [BloomFilter] allocated 127352 bytes for table with 1018784 bits 241s Rank 0 created its Bloom filter 241s Rank 1 created its Bloom filter 241s Rank 1 is counting k-mers in sequence reads [1/2054] 241s Rank 0 is counting k-mers in sequence reads [1/2054] 242s Rank 1 is counting k-mers in sequence reads [2054/2054] (completed) 242s Rank 1 : VirtualCommunicator (service provided by BufferedData): 114119 virtual messages generated 229 real messages (0.200668%) 242s Rank 0 is counting k-mers in sequence reads [2054/2054] (completed) 242s Rank 0 : VirtualCommunicator (service provided by BufferedData): 116591 virtual messages generated 234 real messages (0.200702%) 242s 242s 242s *** 242s Step: K-mer counting 242s Date: Mon Jul 8 20:55:38 2024 242s Elapsed time: 1 seconds 242s Since beginning: 1 seconds 242s *** 242s 242s 242s Rank 1 number of set bits in the Bloom filter: [ 3683 / 1018784 ] (0.361509%) 242s Rank 0 number of set bits in the Bloom filter: [ 4119 / 1018784 ] (0.404306%) 242s Rank 1 destroyed its Bloom filter 242s Rank 0 destroyed its Bloom filter 242s Rank 0 has 1032 k-mers (completed) 242s [BloomFilter] Rank 0: k-mers sampled -> 1032, k-mers dropped -> 0 (0%), k-mers accepted -> 1032 (100%) 242s Rank 0: assembler memory usage: 112836 KiB 242s Rank 1 has 922 k-mers (completed) 242s [BloomFilter] Rank 1: k-mers sampled -> 922, k-mers dropped -> 0 (0%), k-mers accepted -> 922 (100%) 242s Rank 1: assembler memory usage: 116552 KiB 244s 244s 244s Rank 0: the minimum coverage is 3 244s Rank 0: the peak coverage is 3 244s Warning: no peak observed in the k-mer coverage distribution. 244s to deal with the sequencing error rate, try to lower the k-mer length (-k) 244s If you are using RNA-Seq or metagenomic data, then you can ignore this warning. 244s 244s *** 244s Step: Coverage distribution analysis 244s Date: Mon Jul 8 20:55:40 2024 244s Elapsed time: 2 seconds 244s Since beginning: 3 seconds 244s *** 244s 244s 244s 244s Rank 0 is adding edges [1/2054] 244s Rank 1 is adding edges [1/2054] 245s Rank 1 is adding edges [2054/2054] (completed) 245s Rank 1 : VirtualCommunicator (service provided by BufferedData): 224144 virtual messages generated 897 real messages (0.400189%) 245s Rank 1 : VirtualCommunicator (service provided by BufferedData): 224144 virtual messages generated 897 real messages (0.400189%) 245s Rank 0 is adding edges [2054/2054] (completed) 245s Rank 0 : VirtualCommunicator (service provided by BufferedData): 229094 virtual messages generated 917 real messages (0.400272%) 245s Rank 0 : VirtualCommunicator (service provided by BufferedData): 229094 virtual messages generated 917 real messages (0.400272%) 245s 245s *** 245s Step: Graph construction 245s Date: Mon Jul 8 20:55:41 2024 245s Elapsed time: 1 seconds 245s Since beginning: 4 seconds 245s *** 245s 245s 245s Rank 0 has 1032 vertices (completed) 245s Rank 0: assembler memory usage: 112836 KiB 245s Rank 1 has 922 vertices (completed) 245s Rank 1: assembler memory usage: 116552 KiB 247s Rank 1 is purging edges [1/922] 247s Rank 0 is purging edges [1/1032] 247s Rank 0 is purging edges [1032/1032] (completed) 247s Rank 0: assembler memory usage: 113104 KiB 247s VirtualProcessor: completed jobs: 1032 247s Rank 0 : VirtualCommunicator (service provided by VirtualCommunicator): 2062 virtual messages generated 9 real messages (0.436469%) 247s Rank 1 is purging edges [922/922] (completed) 247s Rank 1: assembler memory usage: 116552 KiB 247s VirtualProcessor: completed jobs: 922 247s Rank 1 : VirtualCommunicator (service provided by VirtualCommunicator): 1842 virtual messages generated 11 real messages (0.597177%) 249s Rank 0 wrote test3/degreeDistribution.txt 249s 249s *** 249s Step: Null edge purging 249s Date: Mon Jul 8 20:55:45 2024 249s Elapsed time: 4 seconds 249s Since beginning: 8 seconds 249s *** 249s 249s 249s Rank 0 is selecting optimal read markers [1/2054] 249s Rank 0: assembler memory usage: 113104 KiB 249s Rank 1 is selecting optimal read markers [1/2054] 249s Rank 1: assembler memory usage: 116552 KiB 250s Rank 1 is selecting optimal read markers [2054/2054] (completed) 250s Rank 1: peak number of workers: 1121, maximum: 32768 250s Rank 1 : VirtualCommunicator (service provided by VirtualCommunicator): 118211 virtual messages generated 360 real messages (0.30454%) 250s Rank 1: assembler memory usage: 124232 KiB 250s Rank 1: Freeing unused assembler memory: 4096 KiB freed 250s Rank 1: assembler memory usage: 124232 KiB 250s Rank 0 is selecting optimal read markers [2054/2054] (completed) 250s Rank 0: peak number of workers: 1135, maximum: 32768 250s Rank 0 : VirtualCommunicator (service provided by VirtualCommunicator): 120679 virtual messages generated 369 real messages (0.30577%) 250s Rank 0: assembler memory usage: 121308 KiB 250s Rank 0: Freeing unused assembler memory: 4096 KiB freed 250s Rank 0: assembler memory usage: 121308 KiB 250s 250s *** 250s Step: Selection of optimal read markers 250s Date: Mon Jul 8 20:55:46 2024 250s Elapsed time: 1 seconds 250s Since beginning: 9 seconds 250s *** 250s 250s 250s Rank 1: memory usage for optimal read markers= 4096 KiB 250s Rank 0: memory usage for optimal read markers= 4096 KiB 250s Rank 0 is creating seeds [1/1032] 250s Rank 1 is creating seeds [1/922] 250s Rank 1: assembler memory usage: 124232 KiB 250s Rank 0: assembler memory usage: 121308 KiB 252s Rank 1 has 1 seeds 252s Rank 1 is creating seeds [922/922] (completed) 252s Rank 1: peak number of workers: 916, maximum: 32768 252s Rank 1 : VirtualCommunicator (service provided by VirtualCommunicator): 6519 virtual messages generated 1755 real messages (26.9213%) 252s Rank 1 runtime statistics for seeding algorithm: 252s Rank 1 Skipped paths because of dead end for head: 0 252s Rank 1 Skipped paths because of dead end for tail: 0 252s Rank 1 Skipped paths because of two dead ends: 0 252s Rank 1 Skipped paths because of bubble weak component: 0 252s Rank 1 Skipped paths because of short length: 921 252s Rank 1 Skipped paths because of bad ownership: 0 252s Rank 1 Skipped paths because of low coverage: 0 252s Rank 1 Eligible paths: 1 252s Rank 1: assembler memory usage: 124232 KiB 252s Rank 0 has 0 seeds 252s Rank 0 is creating seeds [1032/1032] (completed) 252s Rank 0: peak number of workers: 998, maximum: 32768 252s Rank 0 : VirtualCommunicator (service provided by VirtualCommunicator): 7093 virtual messages generated 1744 real messages (24.5876%) 252s Rank 0 runtime statistics for seeding algorithm: 252s Rank 0 Skipped paths because of dead end for head: 0 252s Rank 0 Skipped paths because of dead end for tail: 0 252s Rank 0 Skipped paths because of two dead ends: 0 252s Rank 0 Skipped paths because of bubble weak component: 0 252s Rank 0 Skipped paths because of short length: 1031 252s Rank 0 Skipped paths because of bad ownership: 1 252s Rank 0 Skipped paths because of low coverage: 0 252s Rank 0 Eligible paths: 0 252s Rank 0: assembler memory usage: 121308 KiB 252s Rank 1 has 1 seeds to register. 252s Rank 0 registered -1/0 252s Rank 0 registered its seeds 252s Rank 1 registered 0/1 252s Rank 1 registered 0/1 252s Rank 1 registered its seeds 252s VirtualProcessor: completed jobs: 0 252s Rank 1 : VirtualCommunicator (service provided by VirtualCommunicator): 0 virtual messages generated 0 real messages (0%) 252s VirtualProcessor: completed jobs: 0 252s Rank 0 : VirtualCommunicator (service provided by VirtualCommunicator): 0 virtual messages generated 0 real messages (0%) 255s Rank 1 freed 4194304 bytes from the path memory pool (chunks: 1) 255s Rank 0 freed 4194304 bytes from the path memory pool (chunks: 1) 265s Rank 0: gossiping generated 0 messages (gossips: 0 ---> 0) 265s Rank 1: gossiping generated 0 messages (gossips: 0 ---> 0) 265s Rank 0 merged its seeds: 0 seeds -> 0 seeds 265s Rank 1 merged its seeds: 1 seeds -> 1 seeds 265s 265s *** 265s Step: Detection of assembly seeds 265s Date: Mon Jul 8 20:56:01 2024 265s Elapsed time: 15 seconds 265s Since beginning: 24 seconds 265s *** 265s 265s 265s Rank 0 detected 0 library lengths 265s Rank 0 is calculating library lengths [0/0] (completed) 265s Rank 0: peak number of workers: 0, maximum: 32768 265s Rank 0 : VirtualCommunicator (service provided by VirtualCommunicator): 0 virtual messages generated 0 real messages (0%) 265s Rank 0: assembler memory usage: 125404 KiB 265s Rank 1 is calculating library lengths [1/1] 265s Rank 1 detected 1737 library lengths 265s Rank 1 is calculating library lengths [1/1] (completed) 265s Rank 1: peak number of workers: 1, maximum: 32768 265s Rank 1 : VirtualCommunicator (service provided by VirtualCommunicator): 7985 virtual messages generated 7985 real messages (100%) 265s Rank 1: assembler memory usage: 157004 KiB 265s Rank 0 : VirtualCommunicator (service provided by BufferedData): 0 virtual messages generated 0 real messages (0%) 265s Rank 1 : VirtualCommunicator (service provided by BufferedData): 67 virtual messages generated 1 real messages (1.49254%) 265s 265s Mode= 2 signalAverage= 9 265s CURRENT IS NOISE, 244 265s GOT HIT 212 265s 265s 265s Library # 0 (Automatic) -> average length: 214 and standard deviation: 10 265s 265s *** 265s Step: Estimation of outer distances for paired reads 265s Date: Mon Jul 8 20:56:01 2024 265s Elapsed time: 0 seconds 265s Since beginning: 24 seconds 265s *** 265s 265s 265s Rank 0 is extending seeds [0/0] (completed) 265s Rank 0 extended 0 seeds out of 0 (0.00%) 265s Rank 0: assembler memory usage: 125404 KiB 265s Rank 1 starts on seed 0, length is 845, flow 0 [0/1] 268s Rank 1 traversed 1000 nucleotide symbols 268s Rank 1: assembler memory usage: 161100 KiB 268s Rank 1 is extending seeds [1/1] (completed) 268s Rank 1 extended 1 seeds out of 1 (100.00%) 268s Rank 1: assembler memory usage: 161100 KiB 268s Rank 0 starting fusions 268s 268s *** 268s Step: Bidirectional extension of seeds 268s Date: Mon Jul 8 20:56:04 2024 268s Elapsed time: 3 seconds 268s Since beginning: 27 seconds 268s *** 268s 268s 268s Rank 0: starting clear step. cycleNumber= 0 270s Rank 0 adding 0 new fusions 270s Rank 1 adding 0 new fusions 270s Rank 0 cleared, 0 paths 270s Rank 1 cleared, 1 paths 270s Rank 0: starting distribution step 270s Rank 0 is distributing fusions [0/0] (completed) 270s Rank 1 is distributing fusions [1/1] 270s Rank 0 : VirtualCommunicator (service provided by BufferedData): 0 virtual messages generated 0 real messages (0%) 270s Rank 1: assembler memory usage: 161100 KiB 270s Rank 0: assembler memory usage: 125404 KiB 270s Date: Mon Jul 8 20:56:06 2024 270s Date: Mon Jul 8 20:56:06 2024 270s Rank 1 is distributing fusions [1/1] (completed) 270s Rank 1 : VirtualCommunicator (service provided by BufferedData): 970 virtual messages generated 7 real messages (0.721649%) 270s Rank 1: assembler memory usage: 161100 KiB 270s Date: Mon Jul 8 20:56:06 2024 270s Rank 0 tells others to compute fusions. 270s Rank 0 FusionTaskCreator [0/0] 270s Rank 1 FusionTaskCreator assignNextTask [0/2] 270s Rank 1: assembler memory usage: 161100 KiB 270s Statistics: all paths: 0 eliminated during fusing: 0 270s Rank 0: assembler memory usage: 125404 KiB 270s Date: Mon Jul 8 20:56:06 2024 270s VirtualProcessor: completed jobs: 0 270s Rank 0 : VirtualCommunicator (service provided by VirtualCommunicator): 0 virtual messages generated 0 real messages (0%) 270s Rank 1 FusionTaskCreator processWorkerResult [0/2] 270s Rank 1: assembler memory usage: 161100 KiB 270s Date: Mon Jul 8 20:56:06 2024 270s Rank 1 FusionTaskCreator [2/2] 270s Statistics: all paths: 1 eliminated during fusing: 0 270s Rank 1: assembler memory usage: 161100 KiB 270s VirtualProcessor: completed jobs: 2 270s Rank 1 : VirtualCommunicator (service provided by VirtualCommunicator): 10895 virtual messages generated 10895 real messages (100%) 270s Rank 0: starting clear step. cycleNumber= 1 272s Rank 1 adding 0 new fusions 273s Rank 0 adding 0 new fusions 273s Rank 1 cleared, 1 paths 273s Rank 0 cleared, 0 paths 273s Rank 0 is distributing fusions [0/0] (completed) 273s Rank 1 is distributing fusions [1/1] 273s Rank 1: assembler memory usage: 161100 KiB 273s Rank 0 : VirtualCommunicator (service provided by BufferedData): 0 virtual messages generated 0 real messages (0%) 273s Rank 0: assembler memory usage: 125404 KiB 273s Date: Mon Jul 8 20:56:08 2024 273s Date: Mon Jul 8 20:56:08 2024 273s Rank 1 is distributing fusions [1/1] (completed) 273s Rank 1 : VirtualCommunicator (service provided by BufferedData): 970 virtual messages generated 7 real messages (0.721649%) 273s Rank 1: assembler memory usage: 161100 KiB 273s Date: Mon Jul 8 20:56:08 2024 273s Rank 0 JoinerTaskCreator [0/0] 273s Rank 1 JoinerTaskCreator assignNextTask [0/2] 273s Rank 1: assembler memory usage: 161100 KiB 273s Statistics: all paths: 0 eliminated during joining: 0 273s Rank 0: assembler memory usage: 125404 KiB 273s Date: Mon Jul 8 20:56:08 2024 273s Date: Mon Jul 8 20:56:08 2024 273s VirtualProcessor: completed jobs: 0 273s Rank 0 : VirtualCommunicator (service provided by VirtualCommunicator): 0 virtual messages generated 0 real messages (0%) 273s Rank 1 JoinerTaskCreator processWorkerResult [0/2] 273s Rank 1: assembler memory usage: 161100 KiB 273s Date: Mon Jul 8 20:56:09 2024 273s Rank 1 JoinerTaskCreator [2/2] 273s Statistics: all paths: 1 eliminated during joining: 0 273s Rank 1: assembler memory usage: 161100 KiB 273s Date: Mon Jul 8 20:56:09 2024 273s VirtualProcessor: completed jobs: 2 273s Rank 1 : VirtualCommunicator (service provided by VirtualCommunicator): 13805 virtual messages generated 13805 real messages (100%) 275s Rank 1 adding 0 new fusions 275s Rank 0 adding 0 new fusions 275s Rank 1 cleared, 1 paths 275s Rank 0 cleared, 0 paths 275s Rank 0: starting distribution step 275s Rank 0 is distributing fusions [0/0] (completed) 275s Rank 1 is distributing fusions [1/1] 275s Rank 1: assembler memory usage: 161100 KiB 275s Rank 0 : VirtualCommunicator (service provided by BufferedData): 0 virtual messages generated 0 real messages (0%) 275s Rank 0: assembler memory usage: 125404 KiB 275s Date: Mon Jul 8 20:56:11 2024 275s Date: Mon Jul 8 20:56:11 2024 275s Rank 1 is distributing fusions [1/1] (completed) 275s Rank 1 : VirtualCommunicator (service provided by BufferedData): 970 virtual messages generated 7 real messages (0.721649%) 275s Rank 1: assembler memory usage: 161100 KiB 275s Date: Mon Jul 8 20:56:11 2024 275s Rank 0 tells others to compute fusions. 275s Rank 1 FusionTaskCreator assignNextTask [0/2] 275s Rank 0 FusionTaskCreator [0/0] 275s Rank 1: assembler memory usage: 161100 KiB 275s Statistics: all paths: 0 eliminated during fusing: 0 275s Rank 0: assembler memory usage: 125404 KiB 275s Date: Mon Jul 8 20:56:11 2024 275s VirtualProcessor: completed jobs: 0 275s Rank 0 : VirtualCommunicator (service provided by VirtualCommunicator): 0 virtual messages generated 0 real messages (0%) 275s Rank 1 FusionTaskCreator processWorkerResult [0/2] 275s Rank 1: assembler memory usage: 161100 KiB 275s Date: Mon Jul 8 20:56:11 2024 275s Rank 1 FusionTaskCreator [2/2] 275s Statistics: all paths: 1 eliminated during fusing: 0 275s Rank 1: assembler memory usage: 161100 KiB 275s VirtualProcessor: completed jobs: 2 275s Rank 1 : VirtualCommunicator (service provided by VirtualCommunicator): 16715 virtual messages generated 16715 real messages (100%) 275s Rank 0: starting clear step. cycleNumber= 2 277s Rank 0 adding 0 new fusions 277s Rank 1 adding 0 new fusions 277s Rank 0 cleared, 0 paths 277s Rank 1 cleared, 1 paths 277s Rank 0 is distributing fusions [0/0] (completed) 277s Rank 0 : VirtualCommunicator (service provided by BufferedData): 0 virtual messages generated 0 real messages (0%) 277s Rank 1 is distributing fusions [1/1] 277s Rank 0: assembler memory usage: 125404 KiB 277s Rank 1: assembler memory usage: 161100 KiB 277s Date: Mon Jul 8 20:56:13 2024 277s Date: Mon Jul 8 20:56:13 2024 277s Rank 1 is distributing fusions [1/1] (completed) 277s Rank 1 : VirtualCommunicator (service provided by BufferedData): 970 virtual messages generated 7 real messages (0.721649%) 277s Rank 1: assembler memory usage: 161100 KiB 277s Date: Mon Jul 8 20:56:13 2024 277s Rank 0 JoinerTaskCreator [0/0] 277s Rank 1 JoinerTaskCreator assignNextTask [0/2] 277s Statistics: all paths: 0 eliminated during joining: 0 277s Rank 1: assembler memory usage: 161100 KiB 277s Rank 0: assembler memory usage: 125404 KiB 277s Date: Mon Jul 8 20:56:13 2024 277s Date: Mon Jul 8 20:56:13 2024 277s VirtualProcessor: completed jobs: 0 277s Rank 0 : VirtualCommunicator (service provided by VirtualCommunicator): 0 virtual messages generated 0 real messages (0%) 277s Rank 1 JoinerTaskCreator processWorkerResult [0/2] 277s Rank 1: assembler memory usage: 161100 KiB 277s Date: Mon Jul 8 20:56:13 2024 277s Rank 1 JoinerTaskCreator [2/2] 277s Statistics: all paths: 1 eliminated during joining: 0 277s Rank 1: assembler memory usage: 161100 KiB 277s Date: Mon Jul 8 20:56:13 2024 277s VirtualProcessor: completed jobs: 2 277s Rank 1 : VirtualCommunicator (service provided by VirtualCommunicator): 19625 virtual messages generated 19625 real messages (100%) 279s Rank 0 adding 0 new fusions 279s Rank 1 adding 0 new fusions 279s Rank 1 cleared, 1 paths 279s Rank 0 cleared, 0 paths 279s Rank 0: starting distribution step 279s Rank 0 is distributing fusions [0/0] (completed) 279s Rank 1 is distributing fusions [1/1] 279s Rank 1: assembler memory usage: 161100 KiB 279s Rank 0 : VirtualCommunicator (service provided by BufferedData): 0 virtual messages generated 0 real messages (0%) 279s Rank 0: assembler memory usage: 125404 KiB 279s Date: Mon Jul 8 20:56:15 2024 279s Date: Mon Jul 8 20:56:15 2024 279s Rank 1 is distributing fusions [1/1] (completed) 279s Rank 1 : VirtualCommunicator (service provided by BufferedData): 970 virtual messages generated 7 real messages (0.721649%) 279s Rank 1: assembler memory usage: 161100 KiB 279s Date: Mon Jul 8 20:56:15 2024 279s Rank 0 cycleNumber= 2 279s 279s *** 279s Step: Merging of redundant paths 279s Date: Mon Jul 8 20:56:15 2024 279s Elapsed time: 11 seconds 279s Since beginning: 38 seconds 279s *** 279s 279s 279s Rank 0 appended 0 elements 279s Rank 1 appended 1 elements 279s 279s *** 279s Step: Generation of contigs 279s Date: Mon Jul 8 20:56:15 2024 279s Elapsed time: 0 seconds 279s Since beginning: 38 seconds 279s *** 279s 279s Rank 0 finished gathering scaffold links. 279s Rank 0 objectName: 1 => peakCoverage: 237 blockSize: 970 280s Rank 1: gathering scaffold links [1/1] [970/970] (completed) 280s Rank 0 ineligibleObjects: 0/970 (0.00%) 280s Rank 1: assembler memory usage: 161100 KiB 280s contig: 1 vertices: 970 averageCoverage: 237 standardDeviation: 115 peakCoverage: 237 repeatCoverage: 474 280s Rank 0 will write 1 contig lengths 280s Rank 1 finished gathering scaffold links. 280s Rank 0 will solve the scaffolding problem. 280s Welcome to GreedySolver v1.0 280s 1 vertices; 0 edges 280s 1 contigs >= 500 280s Edges in solution: 0 280s 280s Conflict statistics: 280s 1 scaffolds, 1 >= 500 280s Total: 1000 nucleotides 280s 280s *** 280s Step: Scaffolding of contigs 280s Date: Mon Jul 8 20:56:16 2024 280s Elapsed time: 1 seconds 280s Since beginning: 39 seconds 280s *** 280s 280s Rank 0 syncing with master 280s Rank 1 syncing with master 280s 280s *** 280s Step: Counting sequences to search 280s Date: Mon Jul 8 20:56:16 2024 280s Elapsed time: 0 seconds 280s Since beginning: 39 seconds 280s *** 280s 280s 280s Rank 0 will add colors, 0 sequences in 0 files to process 280s Rank 1 will add colors, 0 sequences in 0 files to process 280s Rank 1 : VirtualCommunicator (service provided by BufferedData): 0 virtual messages generated 0 real messages (0.00%) 280s Rank 0 : VirtualCommunicator (service provided by BufferedData): 0 virtual messages generated 0 real messages (0%) 282s 282s *** 282s Step: Graph coloring 282s Date: Mon Jul 8 20:56:18 2024 282s Elapsed time: 2 seconds 282s Since beginning: 41 seconds 282s *** 282s 282s 282s Rank 0: starting SlaveMode= call_RAY_SLAVE_MODE_CONTIG_BIOLOGICAL_ABUNDANCES 282s Rank 1: starting SlaveMode= call_RAY_SLAVE_MODE_CONTIG_BIOLOGICAL_ABUNDANCES 282s Rank 0 shares its counts 282s [IO] Input/output operations for coverage XML objects: 1 / bufferSize: 16777216 bytes 282s Rank 1 computing contig abundances [1/1] [1/970] 282s Rank 1 computing contig abundances [1/1] [970/970] 282s [IO] Input/output operations for coverage XML objects: 1 / bufferSize: 16777216 bytes 282s 282s *** 282s Step: Counting contig biological abundances 282s Date: Mon Jul 8 20:56:18 2024 282s Elapsed time: 0 seconds 282s Since beginning: 41 seconds 282s *** 282s 282s 282s Rank 0 colored the graph with 0 real colors using 1 virtual colors 282s Rank 1 colored the graph with 0 real colors using 1 virtual colors 282s Rank 1 : VirtualCommunicator (service provided by BufferedData): 3880 virtual messages generated 9 real messages (0.23%) 282s Rank 0 : VirtualCommunicator (service provided by BufferedData): 0 virtual messages generated 0 real messages (0%) 282s 282s *** 282s Step: Counting sequence biological abundances 282s Date: Mon Jul 8 20:56:18 2024 282s Elapsed time: 0 seconds 282s Since beginning: 41 seconds 282s *** 282s 282s 282s [IO] Input/output operations for sequence XML objects: 0 / bufferSize: 16777216 bytes 282s [IO] Input/output operations for sequence XML objects: 0 / bufferSize: 16777216 bytes 282s [IO] Input/output operations for identification TSV objects: 0 / bufferSize: 16777216 bytes 282s [IO] Input/output operations for identification TSV objects: 0 / bufferSize: 16777216 bytes 284s Rank 0 has exactly 0 k-mer physical colors for the phylogeny. 284s Rank 1 has exactly 0 k-mer physical colors for the phylogeny. 284s 284s 284s [TaxonomyViewer::copyTaxonsFromSecondaryTable] 0 -> 0 284s Rank 0 is starting taxon syncing across the compute tribe. 284s 284s *** 284s Step: Loading taxons 284s Date: Mon Jul 8 20:56:20 2024 284s Elapsed time: 2 seconds 284s Since beginning: 43 seconds 284s *** 284s 284s Rank 0 synced taxons across the grid with 2 poor slaves. 284s [TaxonomyViewer::copyTaxonsFromSecondaryTable] 0 -> 0 284s [TaxonomyViewer::copyTaxonsFromSecondaryTable] 0 -> 0 284s Rank 0 has 0 taxons after syncing with master 284s Rank 1 has 0 taxons after syncing with master 286s 286s 286s 286s *** 286s Step: Loading tree 286s Date: Mon Jul 8 20:56:22 2024 286s Elapsed time: 2 seconds 286s Since beginning: 45 seconds 286s *** 286s 289s Rank 1 has exactly 0 k-mer physical colors related to EMBL CDS objects. 289s 289s Rank 1: counting ontology terms in the graph... 289s Rank 0 has exactly 0 k-mer physical colors related to EMBL CDS objects. 289s 289s Rank 0: counting ontology terms in the graph... 291s Rank 1: 0 have some biological signal 291s Rank 0: 0 have some biological signal 291s Number of dereferenced alternate handles: 0 291s Number of k-mer observations with gene ontology terms: 0 291s Number of dereferenced alternate handles: 0 291s Number of k-mer observations with gene ontology terms: 0 291s Rank 0: synced ontology term profiles with master 291s Rank 0 Synchronizing kmer observations with gene ontology terms: 0 (from 1) 291s Rank 1: synced ontology term profiles with master 291s Rank 0: synchronization is complete! 291s Rank 0: ontology terms with biological signal: 0 291s Populated recursive values... 291s Gene ontology terms without depth information: 0 291s [GeneOntology] maximum depth for GeneOntologyDomain  is 0 291s [GeneOntology] maximum depth for GeneOntologyDomain [GeneOntology] maximum depth for GeneOntologyDomain  is 0 291s 291s *** 291s Step: Processing gene ontologies 291s Date: Mon Jul 8 20:56:27 2024 291s Elapsed time: 5 seconds 291s Since beginning: 50 seconds 291s *** 291s 291s Rank 1: the CorePlugin GenomeNeighbourhood is disabled... 291s Rank 0: the CorePlugin GenomeNeighbourhood is disabled... 291s [GenomeNeighbourhood] in final list: 0 291s 291s *** 291s Step: Computing neighbourhoods 291s Date: Mon Jul 8 20:56:27 2024 291s Elapsed time: 0 seconds 291s Since beginning: 50 seconds 291s *** 291s 291s Contigs >= 100 nt 291s Number: 1 291s Total length: 1000 291s Average: 1000 291s N50: 1000 291s Median: 1000 291s Largest: 1000 291s Contigs >= 500 nt 291s Number: 1 291s Total length: 1000 291s Average: 1000 291s N50: 1000 291s Median: 1000 291s Largest: 1000 291s Scaffolds >= 100 nt 291s Number: 1 291s Total length: 1000 291s Average: 1000 291s N50: 1000 291s Median: 1000 291s Largest: 1000 291s Scaffolds >= 500 nt 291s Number: 1 291s Total length: 1000 291s Average: 1000 291s N50: 1000 291s Median: 1000 291s Largest: 1000 291s 291s Rank 0 wrote test3/Contigs.fasta 291s Rank 0 wrote test3/Scaffolds.fasta 291s Check for test3/* 291s 291s 291s autopkgtest [20:56:27]: test run-unit-test: -----------------------] 292s run-unit-test PASS 292s autopkgtest [20:56:28]: test run-unit-test: - - - - - - - - - - results - - - - - - - - - - 292s autopkgtest [20:56:28]: @@@@@@@@@@@@@@@@@@@@ summary 292s run-unit-test PASS 303s nova [W] Using flock in scalingstack-bos02-s390x 303s Creating nova instance adt-oracular-s390x-ray-20240708-205136-juju-7f2275-prod-proposed-migration-environment-3-381163e1-2e1a-4d50-927a-5fc061ee2d3f from image adt/ubuntu-oracular-s390x-server-20240708.img (UUID 6c20d52a-e434-4209-aeee-6cc89c5ba4cf)...