01/25 08:21:33 INFO | job:0188| Writing results to /home/ubuntu/autotest/client/results/default 01/25 08:21:33 DEBUG| job:0963| Initializing the state engine 01/25 08:21:33 DEBUG| base_job:0394| Persistent state client.steps now set to [] 01/25 08:21:33 DEBUG| job:0985| Persistent option harness now set to None 01/25 08:21:33 DEBUG| job:0985| Persistent option harness_args now set to None 01/25 08:21:33 DEBUG| harness:0087| Selected harness: standalone 01/25 08:21:34 INFO | job:0215| START ---- ---- timestamp=1548404494 localtime=Jan 25 08:21:34 01/25 08:21:34 DEBUG| base_job:0394| Persistent state client._record_indent now set to 1 01/25 08:21:34 DEBUG| job:0547| Test has timeout: 600 sec. 01/25 08:21:34 INFO | job:0215| START ubuntu_nbd_smoke_test.nbd-smoke-test ubuntu_nbd_smoke_test.nbd-smoke-test timestamp=1548404494 timeout=600 localtime=Jan 25 08:21:34 01/25 08:21:34 DEBUG| base_job:0394| Persistent state client._record_indent now set to 2 01/25 08:21:34 DEBUG| base_job:0394| Persistent state client.unexpected_reboot now set to ('ubuntu_nbd_smoke_test.nbd-smoke-test', 'ubuntu_nbd_smoke_test.nbd-smoke-test') 01/25 08:21:34 DEBUG| job:0509| Waiting for pid 4016 for 600 seconds 01/25 08:21:34 DEBUG| utils:0116| Running 'DEBIAN_FRONTEND=noninteractive apt-get install --yes --force-yes nbd-server nbd-client net-tools gdb' 01/25 08:21:34 DEBUG| utils:0153| [stdout] Reading package lists... 01/25 08:21:34 DEBUG| utils:0153| [stdout] Building dependency tree... 01/25 08:21:34 DEBUG| utils:0153| [stdout] Reading state information... 01/25 08:21:34 DEBUG| utils:0153| [stdout] net-tools is already the newest version (1.60-26ubuntu1). 01/25 08:21:34 DEBUG| utils:0153| [stdout] gdb is already the newest version (7.11.1-0ubuntu1~16.5). 01/25 08:21:34 DEBUG| utils:0153| [stdout] The following package was automatically installed and is no longer required: 01/25 08:21:34 DEBUG| utils:0153| [stdout] grub-pc-bin 01/25 08:21:34 DEBUG| utils:0153| [stdout] Use 'sudo apt autoremove' to remove it. 01/25 08:21:34 DEBUG| utils:0153| [stdout] The following NEW packages will be installed: 01/25 08:21:34 DEBUG| utils:0153| [stdout] nbd-client nbd-server 01/25 08:21:34 DEBUG| utils:0153| [stdout] 0 upgraded, 2 newly installed, 0 to remove and 88 not upgraded. 01/25 08:21:34 DEBUG| utils:0153| [stdout] Need to get 101 kB of archives. 01/25 08:21:34 DEBUG| utils:0153| [stdout] After this operation, 327 kB of additional disk space will be used. 01/25 08:21:34 DEBUG| utils:0153| [stdout] Get:1 http://phx-ad-2.clouds.archive.ubuntu.com/ubuntu xenial/universe amd64 nbd-client amd64 1:3.13-1 [47.6 kB] 01/25 08:21:34 DEBUG| utils:0153| [stdout] Get:2 http://phx-ad-2.clouds.archive.ubuntu.com/ubuntu xenial/main amd64 nbd-server amd64 1:3.13-1 [52.9 kB] 01/25 08:21:35 DEBUG| utils:0153| [stdout] Preconfiguring packages ... 01/25 08:21:35 DEBUG| utils:0153| [stdout] Fetched 101 kB in 0s (286 kB/s) 01/25 08:21:35 DEBUG| utils:0153| [stdout] Selecting previously unselected package nbd-client. 01/25 08:21:35 DEBUG| utils:0153| [stdout] (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 ... 97808 files and directories currently installed.) 01/25 08:21:35 DEBUG| utils:0153| [stdout] Preparing to unpack .../nbd-client_1%3a3.13-1_amd64.deb ... 01/25 08:21:35 DEBUG| utils:0153| [stdout] Unpacking nbd-client (1:3.13-1) ... 01/25 08:21:35 DEBUG| utils:0153| [stdout] Selecting previously unselected package nbd-server. 01/25 08:21:35 DEBUG| utils:0153| [stdout] Preparing to unpack .../nbd-server_1%3a3.13-1_amd64.deb ... 01/25 08:21:35 DEBUG| utils:0153| [stdout] Unpacking nbd-server (1:3.13-1) ... 01/25 08:21:35 DEBUG| utils:0153| [stdout] Processing triggers for man-db (2.7.5-1) ... 01/25 08:21:36 DEBUG| utils:0153| [stdout] Processing triggers for systemd (229-4ubuntu21.4) ... 01/25 08:21:36 DEBUG| utils:0153| [stdout] Processing triggers for ureadahead (0.100.0-19) ... 01/25 08:21:36 DEBUG| utils:0153| [stdout] ureadahead will be reprofiled on next reboot 01/25 08:21:37 DEBUG| utils:0153| [stdout] Setting up nbd-client (1:3.13-1) ... 01/25 08:21:37 DEBUG| utils:0153| [stdout] update-initramfs: deferring update (trigger activated) 01/25 08:21:37 DEBUG| utils:0153| [stdout] update-rc.d: warning: start and stop actions are no longer supported; falling back to defaults 01/25 08:21:37 DEBUG| utils:0153| [stdout] Setting up nbd-server (1:3.13-1) ... 01/25 08:21:37 DEBUG| utils:0153| [stdout] 01/25 08:21:37 DEBUG| utils:0153| [stdout] Creating config file /etc/nbd-server/config with new version 01/25 08:21:38 DEBUG| utils:0153| [stdout] Adding system user `nbd' (UID 113) ... 01/25 08:21:38 DEBUG| utils:0153| [stdout] Adding new group `nbd' (GID 116) ... 01/25 08:21:38 DEBUG| utils:0153| [stdout] Adding new user `nbd' (UID 113) with group `nbd' ... 01/25 08:21:38 DEBUG| utils:0153| [stdout] Not creating home directory `/etc/nbd-server'. 01/25 08:21:38 DEBUG| utils:0153| [stdout] Processing triggers for systemd (229-4ubuntu21.4) ... 01/25 08:21:38 DEBUG| utils:0153| [stdout] Processing triggers for ureadahead (0.100.0-19) ... 01/25 08:21:38 DEBUG| utils:0153| [stdout] Processing triggers for initramfs-tools (0.122ubuntu8.14) ... 01/25 08:21:39 DEBUG| utils:0153| [stdout] update-initramfs: Generating /boot/initrd.img-4.15.0-1008-oracle 01/25 08:21:53 DEBUG| utils:0153| [stdout] W: mdadm: /etc/mdadm/mdadm.conf defines no arrays. 01/25 08:22:04 ERROR| utils:0153| [stderr] W: --force-yes is deprecated, use one of the options starting with --allow instead. 01/25 08:22:04 DEBUG| utils:0116| Running 'rm -f /etc/*/S99autotest || true' 01/25 08:22:05 DEBUG| utils:0116| Running '/home/ubuntu/autotest/client/tests/ubuntu_nbd_smoke_test/ubuntu_nbd_smoke_test.sh' 01/25 08:22:05 DEBUG| utils:0153| [stdout] creating backing nbd image /tmp/nbd_image.img 01/25 08:22:06 DEBUG| utils:0153| [stdout] 01/25 08:22:06 DEBUG| utils:0153| [stdout] -------------------------------------------------------------------------------- 01/25 08:22:06 DEBUG| utils:0153| [stdout] Image path: /tmp/nbd_image.img 01/25 08:22:06 DEBUG| utils:0153| [stdout] Mount point: /mnt/nbd-test-12329 01/25 08:22:06 DEBUG| utils:0153| [stdout] Date: Fri Jan 25 08:22:06 UTC 2019 01/25 08:22:06 DEBUG| utils:0153| [stdout] Host: x-l-oracle-oracle-4-15-0-bm-denseio2-52-nbd-smoke-test 01/25 08:22:06 DEBUG| utils:0153| [stdout] Kernel: 4.15.0-1008-oracle #10~16.04.1-Ubuntu SMP Tue Jan 15 16:23:20 UTC 2019 01/25 08:22:06 DEBUG| utils:0153| [stdout] Machine: x-l-oracle-oracle-4-15-0-bm-denseio2-52-nbd-smoke-test x86_64 x86_64 01/25 08:22:06 DEBUG| utils:0153| [stdout] CPUs online: 104 01/25 08:22:06 DEBUG| utils:0153| [stdout] CPUs total: 104 01/25 08:22:06 DEBUG| utils:0153| [stdout] Page size: 4096 01/25 08:22:06 DEBUG| utils:0153| [stdout] Pages avail: 197176508 01/25 08:22:06 DEBUG| utils:0153| [stdout] Pages total: 197810211 01/25 08:22:06 DEBUG| utils:0153| [stdout] Free space: 01/25 08:22:06 DEBUG| utils:0153| [stdout] Filesystem Size Used Avail Use% Mounted on 01/25 08:22:06 DEBUG| utils:0153| [stdout] udev 378G 0 378G 0% /dev 01/25 08:22:06 DEBUG| utils:0153| [stdout] tmpfs 76G 10M 76G 1% /run 01/25 08:22:06 DEBUG| utils:0153| [stdout] /dev/sda1 45G 2.3G 43G 6% / 01/25 08:22:06 DEBUG| utils:0153| [stdout] tmpfs 378G 0 378G 0% /dev/shm 01/25 08:22:06 DEBUG| utils:0153| [stdout] tmpfs 5.0M 0 5.0M 0% /run/lock 01/25 08:22:06 DEBUG| utils:0153| [stdout] tmpfs 378G 0 378G 0% /sys/fs/cgroup 01/25 08:22:06 DEBUG| utils:0153| [stdout] /dev/sda15 105M 3.4M 101M 4% /boot/efi 01/25 08:22:06 DEBUG| utils:0153| [stdout] tmpfs 76G 0 76G 0% /run/user/1000 01/25 08:22:06 DEBUG| utils:0153| [stdout] -------------------------------------------------------------------------------- 01/25 08:22:06 DEBUG| utils:0153| [stdout] 01/25 08:22:06 DEBUG| utils:0153| [stdout] NBD device /dev/nbd0 created 01/25 08:22:06 DEBUG| utils:0153| [stdout] found nbd export 01/25 08:22:07 DEBUG| utils:0153| [stdout] NBD exports found: 01/25 08:22:07 DEBUG| utils:0153| [stdout] test 01/25 08:22:07 DEBUG| utils:0153| [stdout] starting client with NBD device /dev/nbd0 01/25 08:22:07 DEBUG| utils:0153| [stdout] Negotiation: ..size = 128MB 01/25 08:22:07 ERROR| utils:0153| [stderr] bs=1024, sz=134217728 bytes 01/25 08:22:07 ERROR| utils:0153| [stderr] timeout=30 01/25 08:22:07 DEBUG| utils:0153| [stdout] creating ext4 on /dev/nbd0 01/25 08:22:08 DEBUG| utils:0153| [stdout] mkfs on /dev/nbd0 succeeded after 0 attempt(s) 01/25 08:22:08 DEBUG| utils:0153| [stdout] checking ext4 on /dev/nbd0 01/25 08:22:08 DEBUG| utils:0153| [stdout] fsck from util-linux 2.27.1 01/25 08:22:08 ERROR| utils:0153| [stderr] e2fsck 1.42.13 (17-May-2015) 01/25 08:22:08 DEBUG| utils:0153| [stdout] /dev/nbd0: clean, 11/32768 files, 9787/131072 blocks 01/25 08:22:08 DEBUG| utils:0153| [stdout] 01/25 08:22:08 DEBUG| utils:0153| [stdout] mount: 01/25 08:22:08 DEBUG| utils:0153| [stdout] /dev/nbd0 on /mnt/nbd-test-12329 type ext4 (rw,relatime,data=ordered) 01/25 08:22:08 DEBUG| utils:0153| [stdout] mounted on /dev/nbd0 01/25 08:22:08 DEBUG| utils:0153| [stdout] 01/25 08:22:08 DEBUG| utils:0153| [stdout] free: 01/25 08:22:08 DEBUG| utils:0153| [stdout] Filesystem 1K-blocks Used Available Use% Mounted on 01/25 08:22:08 DEBUG| utils:0153| [stdout] /dev/nbd0 122835 1550 112111 2% /mnt/nbd-test-12329 01/25 08:22:08 DEBUG| utils:0153| [stdout] 01/25 08:22:08 DEBUG| utils:0153| [stdout] creating large file /mnt/nbd-test-12329/largefile 01/25 08:22:08 DEBUG| utils:0153| [stdout] -rw-r--r-- 1 root root 100M Jan 25 08:22 /mnt/nbd-test-12329/largefile 01/25 08:22:08 DEBUG| utils:0153| [stdout] 01/25 08:22:08 DEBUG| utils:0153| [stdout] free: 01/25 08:22:08 DEBUG| utils:0153| [stdout] Filesystem 1K-blocks Used Available Use% Mounted on 01/25 08:22:08 DEBUG| utils:0153| [stdout] /dev/nbd0 122835 103951 9710 92% /mnt/nbd-test-12329 01/25 08:22:08 DEBUG| utils:0153| [stdout] 01/25 08:22:09 DEBUG| utils:0153| [stdout] removing file /mnt/nbd-test-12329/largefile 01/25 08:22:09 DEBUG| utils:0153| [stdout] unmounting /mnt/nbd-test-12329 01/25 08:22:10 DEBUG| utils:0153| [stdout] stopping client 01/25 08:22:10 DEBUG| utils:0153| [stdout] disconnect, sock, done 01/25 08:22:11 DEBUG| utils:0153| [stdout] killing server 01/25 08:22:11 DEBUG| utils:0153| [stdout] ================================================================================ 01/25 08:22:11 ERROR| utils:0153| [stderr] modprobe: FATAL: Module nbd is in use. 01/25 08:22:11 DEBUG| utils:0153| [stdout] Cannot unload Network Block Device module nbd.o 01/25 08:22:11 ERROR| test:0414| Exception escaping from test: Traceback (most recent call last): File "/home/ubuntu/autotest/client/shared/test.py", line 411, in _exec _call_test_function(self.execute, *p_args, **p_dargs) File "/home/ubuntu/autotest/client/shared/test.py", line 823, in _call_test_function return func(*args, **dargs) File "/home/ubuntu/autotest/client/shared/test.py", line 291, in execute postprocess_profiled_run, args, dargs) File "/home/ubuntu/autotest/client/shared/test.py", line 212, in _call_run_once self.run_once(*args, **dargs) File "/home/ubuntu/autotest/client/tests/ubuntu_nbd_smoke_test/ubuntu_nbd_smoke_test.py", line 51, in run_once self.results = utils.system_output(cmd, retain_output=True) File "/home/ubuntu/autotest/client/shared/utils.py", line 1267, in system_output verbose=verbose, args=args).stdout File "/home/ubuntu/autotest/client/shared/utils.py", line 918, in run "Command returned non-zero exit status") CmdError: Command failed, rc=1, Command returned non-zero exit status * Command: /home/ubuntu/autotest/client/tests/ubuntu_nbd_smoke_test/ubuntu_nbd_smoke _test.sh Exit status: 1 Duration: 6.25446605682 stdout: creating backing nbd image /tmp/nbd_image.img -------------------------------------------------------------------------------- Image path: /tmp/nbd_image.img Mount point: /mnt/nbd-test-12329 Date: Fri Jan 25 08:22:06 UTC 2019 Host: x-l-oracle-oracle-4-15-0-bm-denseio2-52-nbd-smoke-test Kernel: 4.15.0-1008-oracle #10~16.04.1-Ubuntu SMP Tue Jan 15 16:23:20 UTC 2019 Machine: x-l-oracle-oracle-4-15-0-bm-denseio2-52-nbd-smoke-test x86_64 x86_64 CPUs online: 104 CPUs total: 104 Page size: 4096 Pages avail: 197176508 Pages total: 197810211 Free space: Filesystem Size Used Avail Use% Mounted on udev 378G 0 378G 0% /dev tmpfs 76G 10M 76G 1% /run /dev/sda1 45G 2.3G 43G 6% / tmpfs 378G 0 378G 0% /dev/shm tmpfs 5.0M 0 5.0M 0% /run/lock tmpfs 378G 0 378G 0% /sys/fs/cgroup /dev/sda15 105M 3.4M 101M 4% /boot/efi tmpfs 76G 0 76G 0% /run/user/1000 -------------------------------------------------------------------------------- NBD device /dev/nbd0 created found nbd export NBD exports found: test starting client with NBD device /dev/nbd0 Negotiation: ..size = 128MB creating ext4 on /dev/nbd0 mkfs on /dev/nbd0 succeeded after 0 attempt(s) checking ext4 on /dev/nbd0 fsck from util-linux 2.27.1 /dev/nbd0: clean, 11/32768 files, 9787/131072 blocks mount: /dev/nbd0 on /mnt/nbd-test-12329 type ext4 (rw,relatime,data=ordered) mounted on /dev/nbd0 free: Filesystem 1K-blocks Used Available Use% Mounted on /dev/nbd0 122835 1550 112111 2% /mnt/nbd-test-12329 creating large file /mnt/nbd-test-12329/largefile -rw-r--r-- 1 root root 100M Jan 25 08:22 /mnt/nbd-test-12329/largefile free: Filesystem 1K-blocks Used Available Use% Mounted on /dev/nbd0 122835 103951 9710 92% /mnt/nbd-test-12329 removing file /mnt/nbd-test-12329/largefile unmounting /mnt/nbd-test-12329 stopping client disconnect, sock, done killing server ================================================================================ Cannot unload Network Block Device module nbd.o stderr: bs=1024, sz=134217728 bytes timeout=30 e2fsck 1.42.13 (17-May-2015) modprobe: FATAL: Module nbd is in use. 01/25 08:22:11 ERROR| parallel:0033| child process failed 01/25 08:22:11 DEBUG| parallel:0037| Traceback (most recent call last): 01/25 08:22:11 DEBUG| parallel:0037| File "/home/ubuntu/autotest/client/parallel.py", line 25, in fork_start 01/25 08:22:11 DEBUG| parallel:0037| l() 01/25 08:22:11 DEBUG| parallel:0037| File "/home/ubuntu/autotest/client/job.py", line 505, in 01/25 08:22:11 DEBUG| parallel:0037| l = lambda: test.runtest(self, url, tag, args, dargs) 01/25 08:22:11 DEBUG| parallel:0037| File "/home/ubuntu/autotest/client/test.py", line 125, in runtest 01/25 08:22:11 DEBUG| parallel:0037| job.sysinfo.log_after_each_iteration) 01/25 08:22:11 DEBUG| parallel:0037| File "/home/ubuntu/autotest/client/shared/test.py", line 913, in runtest 01/25 08:22:11 DEBUG| parallel:0037| mytest._exec(args, dargs) 01/25 08:22:11 DEBUG| parallel:0037| File "/home/ubuntu/autotest/client/shared/test.py", line 411, in _exec 01/25 08:22:11 DEBUG| parallel:0037| _call_test_function(self.execute, *p_args, **p_dargs) 01/25 08:22:11 DEBUG| parallel:0037| File "/home/ubuntu/autotest/client/shared/test.py", line 823, in _call_test_function 01/25 08:22:11 DEBUG| parallel:0037| return func(*args, **dargs) 01/25 08:22:11 DEBUG| parallel:0037| File "/home/ubuntu/autotest/client/shared/test.py", line 291, in execute 01/25 08:22:11 DEBUG| parallel:0037| postprocess_profiled_run, args, dargs) 01/25 08:22:11 DEBUG| parallel:0037| File "/home/ubuntu/autotest/client/shared/test.py", line 212, in _call_run_once 01/25 08:22:11 DEBUG| parallel:0037| self.run_once(*args, **dargs) 01/25 08:22:11 DEBUG| parallel:0037| File "/home/ubuntu/autotest/client/tests/ubuntu_nbd_smoke_test/ubuntu_nbd_smoke_test.py", line 51, in run_once 01/25 08:22:11 DEBUG| parallel:0037| self.results = utils.system_output(cmd, retain_output=True) 01/25 08:22:11 DEBUG| parallel:0037| File "/home/ubuntu/autotest/client/shared/utils.py", line 1267, in system_output 01/25 08:22:11 DEBUG| parallel:0037| verbose=verbose, args=args).stdout 01/25 08:22:11 DEBUG| parallel:0037| File "/home/ubuntu/autotest/client/shared/utils.py", line 918, in run 01/25 08:22:11 DEBUG| parallel:0037| "Command returned non-zero exit status") 01/25 08:22:11 DEBUG| parallel:0037| CmdError: Command failed, rc=1, Command returned non-zero exit status 01/25 08:22:11 DEBUG| parallel:0037| * Command: 01/25 08:22:11 DEBUG| parallel:0037| /home/ubuntu/autotest/client/tests/ubuntu_nbd_smoke_test/ubuntu_nbd_smoke 01/25 08:22:11 DEBUG| parallel:0037| _test.sh 01/25 08:22:11 DEBUG| parallel:0037| Exit status: 1 01/25 08:22:11 DEBUG| parallel:0037| Duration: 6.25446605682 01/25 08:22:11 DEBUG| parallel:0037| 01/25 08:22:11 DEBUG| parallel:0037| stdout: 01/25 08:22:11 DEBUG| parallel:0037| creating backing nbd image /tmp/nbd_image.img 01/25 08:22:11 DEBUG| parallel:0037| 01/25 08:22:11 DEBUG| parallel:0037| -------------------------------------------------------------------------------- 01/25 08:22:11 DEBUG| parallel:0037| Image path: /tmp/nbd_image.img 01/25 08:22:11 DEBUG| parallel:0037| Mount point: /mnt/nbd-test-12329 01/25 08:22:11 DEBUG| parallel:0037| Date: Fri Jan 25 08:22:06 UTC 2019 01/25 08:22:11 DEBUG| parallel:0037| Host: x-l-oracle-oracle-4-15-0-bm-denseio2-52-nbd-smoke-test 01/25 08:22:11 DEBUG| parallel:0037| Kernel: 4.15.0-1008-oracle #10~16.04.1-Ubuntu SMP Tue Jan 15 16:23:20 UTC 2019 01/25 08:22:11 DEBUG| parallel:0037| Machine: x-l-oracle-oracle-4-15-0-bm-denseio2-52-nbd-smoke-test x86_64 x86_64 01/25 08:22:11 DEBUG| parallel:0037| CPUs online: 104 01/25 08:22:11 DEBUG| parallel:0037| CPUs total: 104 01/25 08:22:11 DEBUG| parallel:0037| Page size: 4096 01/25 08:22:11 DEBUG| parallel:0037| Pages avail: 197176508 01/25 08:22:11 DEBUG| parallel:0037| Pages total: 197810211 01/25 08:22:11 DEBUG| parallel:0037| Free space: 01/25 08:22:11 DEBUG| parallel:0037| Filesystem Size Used Avail Use% Mounted on 01/25 08:22:11 DEBUG| parallel:0037| udev 378G 0 378G 0% /dev 01/25 08:22:11 DEBUG| parallel:0037| tmpfs 76G 10M 76G 1% /run 01/25 08:22:11 DEBUG| parallel:0037| /dev/sda1 45G 2.3G 43G 6% / 01/25 08:22:11 DEBUG| parallel:0037| tmpfs 378G 0 378G 0% /dev/shm 01/25 08:22:11 DEBUG| parallel:0037| tmpfs 5.0M 0 5.0M 0% /run/lock 01/25 08:22:11 DEBUG| parallel:0037| tmpfs 378G 0 378G 0% /sys/fs/cgroup 01/25 08:22:11 DEBUG| parallel:0037| /dev/sda15 105M 3.4M 101M 4% /boot/efi 01/25 08:22:11 DEBUG| parallel:0037| tmpfs 76G 0 76G 0% /run/user/1000 01/25 08:22:11 DEBUG| parallel:0037| -------------------------------------------------------------------------------- 01/25 08:22:11 DEBUG| parallel:0037| 01/25 08:22:11 DEBUG| parallel:0037| NBD device /dev/nbd0 created 01/25 08:22:11 DEBUG| parallel:0037| found nbd export 01/25 08:22:11 DEBUG| parallel:0037| NBD exports found: 01/25 08:22:11 DEBUG| parallel:0037| test 01/25 08:22:11 DEBUG| parallel:0037| starting client with NBD device /dev/nbd0 01/25 08:22:11 DEBUG| parallel:0037| Negotiation: ..size = 128MB 01/25 08:22:11 DEBUG| parallel:0037| creating ext4 on /dev/nbd0 01/25 08:22:11 DEBUG| parallel:0037| mkfs on /dev/nbd0 succeeded after 0 attempt(s) 01/25 08:22:11 DEBUG| parallel:0037| checking ext4 on /dev/nbd0 01/25 08:22:11 DEBUG| parallel:0037| fsck from util-linux 2.27.1 01/25 08:22:11 DEBUG| parallel:0037| /dev/nbd0: clean, 11/32768 files, 9787/131072 blocks 01/25 08:22:11 DEBUG| parallel:0037| 01/25 08:22:11 DEBUG| parallel:0037| mount: 01/25 08:22:11 DEBUG| parallel:0037| /dev/nbd0 on /mnt/nbd-test-12329 type ext4 (rw,relatime,data=ordered) 01/25 08:22:11 DEBUG| parallel:0037| mounted on /dev/nbd0 01/25 08:22:11 DEBUG| parallel:0037| 01/25 08:22:11 DEBUG| parallel:0037| free: 01/25 08:22:11 DEBUG| parallel:0037| Filesystem 1K-blocks Used Available Use% Mounted on 01/25 08:22:11 DEBUG| parallel:0037| /dev/nbd0 122835 1550 112111 2% /mnt/nbd-test-12329 01/25 08:22:11 DEBUG| parallel:0037| 01/25 08:22:11 DEBUG| parallel:0037| creating large file /mnt/nbd-test-12329/largefile 01/25 08:22:11 DEBUG| parallel:0037| -rw-r--r-- 1 root root 100M Jan 25 08:22 /mnt/nbd-test-12329/largefile 01/25 08:22:11 DEBUG| parallel:0037| 01/25 08:22:11 DEBUG| parallel:0037| free: 01/25 08:22:11 DEBUG| parallel:0037| Filesystem 1K-blocks Used Available Use% Mounted on 01/25 08:22:11 DEBUG| parallel:0037| /dev/nbd0 122835 103951 9710 92% /mnt/nbd-test-12329 01/25 08:22:11 DEBUG| parallel:0037| 01/25 08:22:11 DEBUG| parallel:0037| removing file /mnt/nbd-test-12329/largefile 01/25 08:22:11 DEBUG| parallel:0037| unmounting /mnt/nbd-test-12329 01/25 08:22:11 DEBUG| parallel:0037| stopping client 01/25 08:22:11 DEBUG| parallel:0037| disconnect, sock, done 01/25 08:22:11 DEBUG| parallel:0037| killing server 01/25 08:22:11 DEBUG| parallel:0037| ================================================================================ 01/25 08:22:11 DEBUG| parallel:0037| Cannot unload Network Block Device module nbd.o 01/25 08:22:11 DEBUG| parallel:0037| stderr: 01/25 08:22:11 DEBUG| parallel:0037| bs=1024, sz=134217728 bytes 01/25 08:22:11 DEBUG| parallel:0037| timeout=30 01/25 08:22:11 DEBUG| parallel:0037| e2fsck 1.42.13 (17-May-2015) 01/25 08:22:11 DEBUG| parallel:0037| modprobe: FATAL: Module nbd is in use. 01/25 08:22:12 INFO | job:0215| ERROR ubuntu_nbd_smoke_test.nbd-smoke-test ubuntu_nbd_smoke_test.nbd-smoke-test timestamp=1548404532 localtime=Jan 25 08:22:12 Command failed, rc=1, Command returned non-zero exit status * Command: /home/ubuntu/autotest/client/tests/ubuntu_nbd_smoke_test/ubuntu_nbd_smoke _test.sh Exit status: 1 Duration: 6.25446605682 stdout: creating backing nbd image /tmp/nbd_image.img -------------------------------------------------------------------------------- Image path: /tmp/nbd_image.img Mount point: /mnt/nbd-test-12329 Date: Fri Jan 25 08:22:06 UTC 2019 Host: x-l-oracle-oracle-4-15-0-bm-denseio2-52-nbd-smoke-test Kernel: 4.15.0-1008-oracle #10~16.04.1-Ubuntu SMP Tue Jan 15 16:23:20 UTC 2019 Machine: x-l-oracle-oracle-4-15-0-bm-denseio2-52-nbd-smoke-test x86_64 x86_64 CPUs online: 104 CPUs total: 104 Page size: 4096 Pages avail: 197176508 Pages total: 197810211 Free space: Filesystem Size Used Avail Use% Mounted on udev 378G 0 378G 0% /dev tmpfs 76G 10M 76G 1% /run /dev/sda1 45G 2.3G 43G 6% / tmpfs 378G 0 378G 0% /dev/shm tmpfs 5.0M 0 5.0M 0% /run/lock tmpfs 378G 0 378G 0% /sys/fs/cgroup /dev/sda15 105M 3.4M 101M 4% /boot/efi tmpfs 76G 0 76G 0% /run/user/1000 -------------------------------------------------------------------------------- NBD device /dev/nbd0 created found nbd export NBD exports found: test starting client with NBD device /dev/nbd0 Negotiation: ..size = 128MB creating ext4 on /dev/nbd0 mkfs on /dev/nbd0 succeeded after 0 attempt(s) checking ext4 on /dev/nbd0 fsck from util-linux 2.27.1 /dev/nbd0: clean, 11/32768 files, 9787/131072 blocks mount: /dev/nbd0 on /mnt/nbd-test-12329 type ext4 (rw,relatime,data=ordered) mounted on /dev/nbd0 free: Filesystem 1K-blocks Used Available Use% Mounted on /dev/nbd0 122835 1550 112111 2% /mnt/nbd-test-12329 creating large file /mnt/nbd-test-12329/largefile -rw-r--r-- 1 root root 100M Jan 25 08:22 /mnt/nbd-test-12329/largefile free: Filesystem 1K-blocks Used Available Use% Mounted on /dev/nbd0 122835 103951 9710 92% /mnt/nbd-test-12329 removing file /mnt/nbd-test-12329/largefile unmounting /mnt/nbd-test-12329 stopping client disconnect, sock, done killing server ================================================================================ Cannot unload Network Block Device module nbd.o stderr: bs=1024, sz=134217728 bytes timeout=30 e2fsck 1.42.13 (17-May-2015) modprobe: FATAL: Module nbd is in use. 01/25 08:22:12 INFO | job:0215| END ERROR ubuntu_nbd_smoke_test.nbd-smoke-test ubuntu_nbd_smoke_test.nbd-smoke-test timestamp=1548404532 localtime=Jan 25 08:22:12 01/25 08:22:12 DEBUG| base_job:0394| Persistent state client._record_indent now set to 1 01/25 08:22:12 DEBUG| base_job:0428| Persistent state client.unexpected_reboot deleted 01/25 08:22:12 INFO | job:0215| END GOOD ---- ---- timestamp=1548404532 localtime=Jan 25 08:22:12 01/25 08:22:12 DEBUG| base_job:0394| Persistent state client._record_indent now set to 0 01/25 08:22:12 INFO | report:0295| Report successfully generated at /home/ubuntu/autotest/client/results/default/job_report.html