openzfs / zfs

OpenZFS on Linux and FreeBSD
https://openzfs.github.io/openzfs-docs
Other
10.63k stars 1.75k forks source link

Test: PERF sequential_reads_dbuf_cached fails #7666

Closed gmelikov closed 3 years ago

gmelikov commented 6 years ago

System information

Type Version/Name
Distribution Name Ubuntu
Distribution Version 18.04
Linux Kernel
Architecture x86_64
ZFS Version da2feb4
SPL Version da2feb4

Describe the problem you're observing

In our buildbot, http://build.zfsonlinux.org/builders/Ubuntu%2018.04%20x86_64%20%28PERF%29/builds/197/steps/shell_5/logs/summary , test tests/perf/regression/sequential_reads_dbuf_cached fails, but buildbot passes.

Describe how to reproduce the problem

Include any warning/errors/backtraces from the system logs

Test: /var/lib/buildbot/slaves/buildslave1/Ubuntu_18_04_x86_64__PERF_/build/zfs/tests/zfs-tests/tests/perf/regression/sequential_reads_dbuf_cached (run as root) [00:03] [FAIL]
08:17:12.14 removed all registered handlers
08:17:12.15 SUCCESS: zinject -c all
08:17:12.56 SUCCESS: zpool destroy -f perfpool
08:17:13.40 SUCCESS: zpool create -f perfpool virtio-D00 virtio-D01 virtio-D02
08:17:13.59 SUCCESS: zfs create -o recsize=8k -o compress=lz4 -o checksum=sha256 -o redundant_metadata=most perfpool/fs1
08:17:14.05 job: (g=0): rw=write, bs=(R) 1024KiB-1024KiB, (W) 1024KiB-1024KiB, (T) 1024KiB-1024KiB, ioengine=psync, iodepth=1
08:17:14.05 ...
08:17:14.05 fio-3.1
08:17:14.05 Starting 64 threads
08:17:14.05 
08:17:14.05 
08:17:14.05 Run status group 0 (all jobs):
08:17:14.15 ERROR: fio /var/lib/buildbot/slaves/buildslave1/Ubuntu_18_04_x86_64__PERF_/build/zfs/tests/zfs-tests/tests/perf/fio/mkfiles.fio exited 64
08:17:14.15 fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set fio: blocksize too large for data set
08:17:14.16 NOTE: Performing test-fail callback (/var/lib/buildbot/slaves/buildslave1/Ubuntu_18_04_x86_64__PERF_/build/zfs/tests/zfs-tests/callbacks/zfs_dbgmsg.ksh)
08:17:14.16 =================================================================
08:17:14.16  Tailing last 200 lines of zfs_dbgmsg log
08:17:14.16 =================================================================
08:17:14.18 1530194197   spa_history.c:318:spa_history_log_sync(): txg 4 create pool version 5000; software version 5000/5; uts perf-builder 4.15.0-15-generic #16-Ubuntu SMP Wed Apr 4 13:58:14 UTC 2018 x86_64
08:17:14.18 1530194197   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@async_destroy=enabled
08:17:14.18 1530194197   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@empty_bpobj=enabled
08:17:14.18 1530194197   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@lz4_compress=enabled
08:17:14.18 1530194197   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@multi_vdev_crash_dump=enabled
08:17:14.18 1530194197   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@enabled_txg=enabled
08:17:14.18 1530194197   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@hole_birth=enabled
08:17:14.18 1530194197   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@extensible_dataset=enabled
08:17:14.18 1530194197   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@embedded_data=enabled
08:17:14.18 1530194197   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@bookmarks=enabled
08:17:14.18 1530194197   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@filesystem_limits=enabled
08:17:14.18 1530194197   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@large_blocks=enabled
08:17:14.18 1530194197   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@large_dnode=enabled
08:17:14.18 1530194197   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@sha512=enabled
08:17:14.18 1530194197   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@skein=enabled
08:17:14.18 1530194197   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@edonr=enabled
08:17:14.18 1530194197   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@userobj_accounting=enabled
08:17:14.18 1530194197   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@encryption=enabled
08:17:14.18 1530194197   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@project_quota=enabled
08:17:14.18 1530194197   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@device_removal=enabled
08:17:14.18 1530194197   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@obsolete_counts=enabled
08:17:14.18 1530194197   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@zpool_checkpoint=enabled
08:17:14.18 1530194197   spa_history.c:305:spa_history_log_sync(): command: zpool create -f perfpool virtio-D00 virtio-D01 virtio-D02
08:17:14.18 1530194198   spa_history.c:305:spa_history_log_sync(): command: zpool destroy -f perfpool
08:17:14.18 1530194198   spa_misc.c:406:spa_load_note(): spa_load(perfpool, config trusted): UNLOADING
08:17:14.18 1530194199   vdev_disk.c:199:vdev_elevator_switch(): Unable to set "noop" scheduler for /dev/disk/by-id/virtio-D02-part1 (vdd): 256
08:17:14.18 1530194199   vdev_disk.c:199:vdev_elevator_switch(): Unable to set "noop" scheduler for /dev/disk/by-id/virtio-D01-part1 (vdc): 256
08:17:14.18 1530194199   vdev_disk.c:199:vdev_elevator_switch(): Unable to set "noop" scheduler for /dev/disk/by-id/virtio-D00-part1 (vdb): 256
08:17:14.18 1530194199   spa_history.c:318:spa_history_log_sync(): txg 4 create pool version 5000; software version 5000/5; uts perf-builder 4.15.0-15-generic #16-Ubuntu SMP Wed Apr 4 13:58:14 UTC 2018 x86_64
08:17:14.18 1530194199   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@async_destroy=enabled
08:17:14.18 1530194199   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@empty_bpobj=enabled
08:17:14.18 1530194199   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@lz4_compress=enabled
08:17:14.18 1530194199   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@multi_vdev_crash_dump=enabled
08:17:14.18 1530194199   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@spacemap_histogram=enabled
08:17:14.18 1530194199   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@enabled_txg=enabled
08:17:14.18 1530194199   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@hole_birth=enabled
08:17:14.18 1530194199   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@extensible_dataset=enabled
08:17:14.18 1530194199   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@embedded_data=enabled
08:17:14.18 1530194199   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@bookmarks=enabled
08:17:14.18 1530194199   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@filesystem_limits=enabled
08:17:14.18 1530194199   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@large_blocks=enabled
08:17:14.18 1530194199   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@large_dnode=enabled
08:17:14.18 1530194199   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@sha512=enabled
08:17:14.18 1530194199   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@skein=enabled
08:17:14.18 1530194199   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@edonr=enabled
08:17:14.18 1530194199   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@encryption=enabled
08:17:14.18 1530194199   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@project_quota=enabled
08:17:14.18 1530194199   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@device_removal=enabled
08:17:14.18 1530194199   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@obsolete_counts=enabled
08:17:14.18 1530194199   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@zpool_checkpoint=enabled
08:17:14.18 1530194199   spa_history.c:305:spa_history_log_sync(): command: zpool create -f perfpool virtio-D00 virtio-D01 virtio-D02
08:17:14.18 1530194200   spa_history.c:313:spa_history_log_sync(): txg 8 create perfpool/fs1 (id 131) 
08:17:14.18 1530194200   spa_history.c:313:spa_history_log_sync(): txg 9 set perfpool/fs1 (id 131) recordsize=8192
08:17:14.18 1530194200   spa_history.c:313:spa_history_log_sync(): txg 9 set perfpool/fs1 (id 131) compression=15
08:17:14.18 1530194200   spa_history.c:313:spa_history_log_sync(): txg 9 set perfpool/fs1 (id 131) checksum=8
08:17:14.18 1530194200   spa_history.c:313:spa_history_log_sync(): txg 9 set perfpool/fs1 (id 131) redundant_metadata=1
08:17:14.18 1530194201   spa_history.c:338:spa_history_log_sync(): ioctl create
08:17:14.18 1530194201   spa_history.c:305:spa_history_log_sync(): command: zfs create -o recsize=8k -o compress=lz4 -o checksum=sha256 -o redundant_metadata=most perfpool/fs1
08:17:14.18 1530195059   metaslab.c:2129:metaslab_condense(): condensing: txg 180, msp[0] 000000003350867a, vdev id 2, spa perfpool, smp size 16480, segments 123, forcing condense=FALSE
08:17:14.18 1530195064   metaslab.c:2129:metaslab_condense(): condensing: txg 181, msp[0] 00000000e635c92e, vdev id 1, spa perfpool, smp size 16408, segments 113, forcing condense=FALSE
08:17:14.18 1530195064   metaslab.c:2129:metaslab_condense(): condensing: txg 181, msp[0] 00000000de18badc, vdev id 0, spa perfpool, smp size 16472, segments 105, forcing condense=FALSE
08:17:14.18 1530195920   metaslab.c:2129:metaslab_condense(): condensing: txg 348, msp[0] 000000003350867a, vdev id 2, spa perfpool, smp size 16408, segments 125, forcing condense=FALSE
08:17:14.18 1530195930   metaslab.c:2129:metaslab_condense(): condensing: txg 350, msp[0] 00000000de18badc, vdev id 0, spa perfpool, smp size 16400, segments 106, forcing condense=FALSE
08:17:14.18 1530195940   metaslab.c:2129:metaslab_condense(): condensing: txg 352, msp[0] 00000000e635c92e, vdev id 1, spa perfpool, smp size 16464, segments 112, forcing condense=FALSE
08:17:14.18 1530196614   spa_history.c:305:spa_history_log_sync(): command: zpool destroy -f perfpool
08:17:14.18 1530196614   spa_misc.c:406:spa_load_note(): spa_load(perfpool, config trusted): UNLOADING
08:17:14.18 1530196615   vdev_disk.c:199:vdev_elevator_switch(): Unable to set "noop" scheduler for /dev/disk/by-id/virtio-D01-part1 (vdc): 256
08:17:14.18 1530196615   vdev_disk.c:199:vdev_elevator_switch(): Unable to set "noop" scheduler for /dev/disk/by-id/virtio-D02-part1 (vdd): 256
08:17:14.18 1530196615   vdev_disk.c:199:vdev_elevator_switch(): Unable to set "noop" scheduler for /dev/disk/by-id/virtio-D00-part1 (vdb): 256
08:17:14.18 1530196615   spa_history.c:318:spa_history_log_sync(): txg 4 create pool version 5000; software version 5000/5; uts perf-builder 4.15.0-15-generic #16-Ubuntu SMP Wed Apr 4 13:58:14 UTC 2018 x86_64
08:17:14.18 1530196615   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@async_destroy=enabled
08:17:14.18 1530196615   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@empty_bpobj=enabled
08:17:14.18 1530196615   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@lz4_compress=enabled
08:17:14.18 1530196615   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@multi_vdev_crash_dump=enabled
08:17:14.18 1530196615   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@spacemap_histogram=enabled
08:17:14.18 1530196615   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@enabled_txg=enabled
08:17:14.18 1530196615   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@hole_birth=enabled
08:17:14.18 1530196615   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@extensible_dataset=enabled
08:17:14.18 1530196615   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@embedded_data=enabled
08:17:14.18 1530196615   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@filesystem_limits=enabled
08:17:14.18 1530196615   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@large_blocks=enabled
08:17:14.18 1530196615   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@large_dnode=enabled
08:17:14.18 1530196615   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@sha512=enabled
08:17:14.18 1530196615   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@skein=enabled
08:17:14.18 1530196615   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@edonr=enabled
08:17:14.18 1530196615   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@userobj_accounting=enabled
08:17:14.18 1530196615   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@encryption=enabled
08:17:14.18 1530196615   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@project_quota=enabled
08:17:14.18 1530196615   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@device_removal=enabled
08:17:14.18 1530196615   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@obsolete_counts=enabled
08:17:14.18 1530196615   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@zpool_checkpoint=enabled
08:17:14.18 1530196615   spa_history.c:305:spa_history_log_sync(): command: zpool create -f perfpool virtio-D00 virtio-D01 virtio-D02
08:17:14.18 1530196616   spa_history.c:305:spa_history_log_sync(): command: zpool destroy -f perfpool
08:17:14.18 1530196616   spa_misc.c:406:spa_load_note(): spa_load(perfpool, config trusted): UNLOADING
08:17:14.18 1530196616   vdev_disk.c:199:vdev_elevator_switch(): Unable to set "noop" scheduler for /dev/disk/by-id/virtio-D00-part1 (vdb): 256
08:17:14.18 1530196616   vdev_disk.c:199:vdev_elevator_switch(): Unable to set "noop" scheduler for /dev/disk/by-id/virtio-D01-part1 (vdc): 256
08:17:14.18 1530196616   vdev_disk.c:199:vdev_elevator_switch(): Unable to set "noop" scheduler for /dev/disk/by-id/virtio-D02-part1 (vdd): 256
08:17:14.18 1530196616   spa_history.c:318:spa_history_log_sync(): txg 4 create pool version 5000; software version 5000/5; uts perf-builder 4.15.0-15-generic #16-Ubuntu SMP Wed Apr 4 13:58:14 UTC 2018 x86_64
08:17:14.18 1530196616   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@async_destroy=enabled
08:17:14.18 1530196616   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@empty_bpobj=enabled
08:17:14.18 1530196616   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@lz4_compress=enabled
08:17:14.18 1530196616   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@multi_vdev_crash_dump=enabled
08:17:14.18 1530196616   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@spacemap_histogram=enabled
08:17:14.18 1530196616   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@enabled_txg=enabled
08:17:14.18 1530196616   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@hole_birth=enabled
08:17:14.18 1530196616   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@extensible_dataset=enabled
08:17:14.18 1530196616   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@embedded_data=enabled
08:17:14.18 1530196616   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@bookmarks=enabled
08:17:14.18 1530196616   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@filesystem_limits=enabled
08:17:14.18 1530196616   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@large_blocks=enabled
08:17:14.18 1530196616   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@large_dnode=enabled
08:17:14.18 1530196616   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@sha512=enabled
08:17:14.18 1530196616   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@skein=enabled
08:17:14.18 1530196616   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@edonr=enabled
08:17:14.18 1530196616   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@userobj_accounting=enabled
08:17:14.18 1530196616   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@encryption=enabled
08:17:14.18 1530196616   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@project_quota=enabled
08:17:14.18 1530196616   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@device_removal=enabled
08:17:14.18 1530196616   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@obsolete_counts=enabled
08:17:14.18 1530196617   spa_history.c:305:spa_history_log_sync(): command: zpool create -f perfpool virtio-D00 virtio-D01 virtio-D02
08:17:14.18 1530196617   spa_history.c:313:spa_history_log_sync(): txg 8 create perfpool/fs1 (id 67) 
08:17:14.18 1530196617   spa_history.c:313:spa_history_log_sync(): txg 9 set perfpool/fs1 (id 67) recordsize=8192
08:17:14.18 1530196617   spa_history.c:313:spa_history_log_sync(): txg 9 set perfpool/fs1 (id 67) compression=15
08:17:14.18 1530196617   spa_history.c:313:spa_history_log_sync(): txg 9 set perfpool/fs1 (id 67) checksum=8
08:17:14.18 1530196617   spa_history.c:313:spa_history_log_sync(): txg 9 set perfpool/fs1 (id 67) redundant_metadata=1
08:17:14.18 1530196618   spa_history.c:338:spa_history_log_sync(): ioctl create
08:17:14.18 1530196618   spa_history.c:305:spa_history_log_sync(): command: zfs create -o recsize=8k -o compress=lz4 -o checksum=sha256 -o redundant_metadata=most perfpool/fs1
08:17:14.18 1530196625   spa_history.c:313:spa_history_log_sync(): txg 14 snapshot perfpool/fs1@testsnap (id 384) 
08:17:14.18 1530196626   spa_history.c:338:spa_history_log_sync(): ioctl snapshot
08:17:14.18 1530196626   spa_history.c:305:spa_history_log_sync(): command: zfs snapshot perfpool/fs1@testsnap
08:17:14.18 1530196626   spa_history.c:313:spa_history_log_sync(): txg 15 clone perfpool/testclone (id 389) origin=perfpool/fs1@testsnap (384)
08:17:14.18 1530196626   spa_history.c:338:spa_history_log_sync(): ioctl clone
08:17:14.18 1530196626   spa_history.c:305:spa_history_log_sync(): command: zfs clone perfpool/fs1@testsnap perfpool/testclone
08:17:14.18 1530197394   metaslab.c:2129:metaslab_condense(): condensing: txg 166, msp[0] 00000000581044d8, vdev id 2, spa perfpool, smp size 16472, segments 134, forcing condense=FALSE
08:17:14.18 1530197394   metaslab.c:2129:metaslab_condense(): condensing: txg 166, msp[0] 00000000488f8aa6, vdev id 0, spa perfpool, smp size 16472, segments 147, forcing condense=FALSE
08:17:14.18 1530197404   metaslab.c:2129:metaslab_condense(): condensing: txg 168, msp[0] 00000000f4d118a9, vdev id 1, spa perfpool, smp size 16448, segments 111, forcing condense=FALSE
08:17:14.18 1530198229   metaslab.c:2129:metaslab_condense(): condensing: txg 329, msp[0] 00000000581044d8, vdev id 2, spa perfpool, smp size 16432, segments 135, forcing condense=FALSE
08:17:14.18 1530198234   metaslab.c:2129:metaslab_condense(): condensing: txg 330, msp[0] 00000000488f8aa6, vdev id 0, spa perfpool, smp size 16448, segments 148, forcing condense=FALSE
08:17:14.18 1530198244   metaslab.c:2129:metaslab_condense(): condensing: txg 332, msp[0] 00000000f4d118a9, vdev id 1, spa perfpool, smp size 16400, segments 113, forcing condense=FALSE
08:17:14.18 1530199030   spa_history.c:305:spa_history_log_sync(): command: zpool destroy -f perfpool
08:17:14.18 1530199030   spa_misc.c:406:spa_load_note(): spa_load(perfpool, config trusted): UNLOADING
08:17:14.18 1530199031   vdev_disk.c:199:vdev_elevator_switch(): Unable to set "noop" scheduler for /dev/disk/by-id/virtio-D02-part1 (vdd): 256
08:17:14.18 1530199031   vdev_disk.c:199:vdev_elevator_switch(): Unable to set "noop" scheduler for /dev/disk/by-id/virtio-D00-part1 (vdb): 256
08:17:14.18 1530199031   vdev_disk.c:199:vdev_elevator_switch(): Unable to set "noop" scheduler for /dev/disk/by-id/virtio-D01-part1 (vdc): 256
08:17:14.18 1530199031   spa_history.c:318:spa_history_log_sync(): txg 4 create pool version 5000; software version 5000/5; uts perf-builder 4.15.0-15-generic #16-Ubuntu SMP Wed Apr 4 13:58:14 UTC 2018 x86_64
08:17:14.18 1530199031   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@async_destroy=enabled
08:17:14.18 1530199031   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@empty_bpobj=enabled
08:17:14.18 1530199031   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@lz4_compress=enabled
08:17:14.18 1530199031   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@multi_vdev_crash_dump=enabled
08:17:14.18 1530199031   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@spacemap_histogram=enabled
08:17:14.18 1530199031   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@enabled_txg=enabled
08:17:14.18 1530199031   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@hole_birth=enabled
08:17:14.18 1530199031   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@extensible_dataset=enabled
08:17:14.18 1530199031   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@bookmarks=enabled
08:17:14.18 1530199031   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@filesystem_limits=enabled
08:17:14.18 1530199031   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@large_blocks=enabled
08:17:14.18 1530199031   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@large_dnode=enabled
08:17:14.18 1530199031   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@sha512=enabled
08:17:14.18 1530199031   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@skein=enabled
08:17:14.18 1530199031   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@edonr=enabled
08:17:14.18 1530199031   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@userobj_accounting=enabled
08:17:14.18 1530199031   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@encryption=enabled
08:17:14.18 1530199031   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@project_quota=enabled
08:17:14.18 1530199031   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@device_removal=enabled
08:17:14.18 1530199031   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@obsolete_counts=enabled
08:17:14.18 1530199031   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@zpool_checkpoint=enabled
08:17:14.18 1530199032   spa_history.c:305:spa_history_log_sync(): command: zpool create -f perfpool virtio-D00 virtio-D01 virtio-D02
08:17:14.18 1530199032   spa_history.c:305:spa_history_log_sync(): command: zpool destroy -f perfpool
08:17:14.18 1530199032   spa_misc.c:406:spa_load_note(): spa_load(perfpool, config trusted): UNLOADING
08:17:14.18 1530199033   vdev_disk.c:199:vdev_elevator_switch(): Unable to set "noop" scheduler for /dev/disk/by-id/virtio-D02-part1 (vdd): 256
08:17:14.18 1530199033   vdev_disk.c:199:vdev_elevator_switch(): Unable to set "noop" scheduler for /dev/disk/by-id/virtio-D00-part1 (vdb): 256
08:17:14.18 1530199033   vdev_disk.c:199:vdev_elevator_switch(): Unable to set "noop" scheduler for /dev/disk/by-id/virtio-D01-part1 (vdc): 256
08:17:14.18 1530199033   spa_history.c:318:spa_history_log_sync(): txg 4 create pool version 5000; software version 5000/5; uts perf-builder 4.15.0-15-generic #16-Ubuntu SMP Wed Apr 4 13:58:14 UTC 2018 x86_64
08:17:14.18 1530199033   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@async_destroy=enabled
08:17:14.18 1530199033   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@empty_bpobj=enabled
08:17:14.18 1530199033   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@lz4_compress=enabled
08:17:14.18 1530199033   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@multi_vdev_crash_dump=enabled
08:17:14.18 1530199033   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@spacemap_histogram=enabled
08:17:14.18 1530199033   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@enabled_txg=enabled
08:17:14.18 1530199033   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@hole_birth=enabled
08:17:14.18 1530199033   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@extensible_dataset=enabled
08:17:14.18 1530199033   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@embedded_data=enabled
08:17:14.18 1530199033   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@bookmarks=enabled
08:17:14.18 1530199033   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@filesystem_limits=enabled
08:17:14.18 1530199033   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@large_blocks=enabled
08:17:14.18 1530199033   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@large_dnode=enabled
08:17:14.18 1530199033   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@sha512=enabled
08:17:14.18 1530199033   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@skein=enabled
08:17:14.18 1530199033   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@edonr=enabled
08:17:14.18 1530199033   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@userobj_accounting=enabled
08:17:14.18 1530199033   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@encryption=enabled
08:17:14.18 1530199033   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@project_quota=enabled
08:17:14.18 1530199033   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@device_removal=enabled
08:17:14.18 1530199033   spa_history.c:318:spa_history_log_sync(): txg 4 set feature@zpool_checkpoint=enabled
08:17:14.18 1530199033   spa_history.c:305:spa_history_log_sync(): command: zpool create -f perfpool virtio-D00 virtio-D01 virtio-D02
08:17:14.18 1530199033   spa_history.c:313:spa_history_log_sync(): txg 8 create perfpool/fs1 (id 259) 
08:17:14.18 1530199033   spa_history.c:313:spa_history_log_sync(): txg 9 set perfpool/fs1 (id 259) recordsize=8192
08:17:14.18 1530199033   spa_history.c:313:spa_history_log_sync(): txg 9 set perfpool/fs1 (id 259) compression=15
08:17:14.18 1530199033   spa_history.c:313:spa_history_log_sync(): txg 9 set perfpool/fs1 (id 259) checksum=8
08:17:14.18 1530199033   spa_history.c:313:spa_history_log_sync(): txg 9 set perfpool/fs1 (id 259) redundant_metadata=1
08:17:14.18 =================================================================
08:17:14.18  End of zfs_dbgmsg log
08:17:14.18 =================================================================
08:17:14.19 NOTE: Performing test-fail callback (/var/lib/buildbot/slaves/buildslave1/Ubuntu_18_04_x86_64__PERF_/build/zfs/tests/zfs-tests/callbacks/zfs_dmesg.ksh)
08:17:14.19 =================================================================
08:17:14.19  Tailing last 200 lines of dmesg log
08:17:14.19 =================================================================
08:17:14.22 [25582.210492] 0000000055438c45: ffff91e275789660 (0xffff91e275789660)
08:17:14.22 [25582.210495] 00000000aaa48a79: ffffae730394fe40 (0xffffae730394fe40)
08:17:14.22 [25582.210497] 00000000b0827804: ffffae730394ff00 (0xffffae730394ff00)
08:17:14.22 [25582.210510] 0000000075ef663d: ffffffffc088581b (taskq_thread+0x2ab/0x4e0 [spl])
08:17:14.22 [25582.210513] 00000000235867e7: ffff91e278ea7bd8 (0xffff91e278ea7bd8)
08:17:14.22 [25582.210516] 00000000f9932f46: ffff91e275789670 (0xffff91e275789670)
08:17:14.22 [25582.210519] 00000000645f98f1: ffff91e278ea7b80 (0xffff91e278ea7b80)
08:17:14.22 [25582.210522] 00000000d811b6e9: 0000000000000286 (0x286)
08:17:14.22 [25582.210524] 00000000db56b3ff: 0000000000000000 ...
08:17:14.22 [25582.210526] 000000002d22917b: 0000000000000001 (0x1)
08:17:14.22 [25582.210529] 00000000732eaf9f: ffff91e14adcdc00 (0xffff91e14adcdc00)
08:17:14.22 [25582.210747] 000000002e533f61: ffffffff998b8090 (wake_up_q+0x80/0x80)
08:17:14.22 [25582.210752] 00000000b3f3b440: dead000000000100 (0xdead000000000100)
08:17:14.22 [25582.210754] 00000000dbca937f: dead000000000200 (0xdead000000000200)
08:17:14.22 [25582.210756] 000000008417f71a: 0000000000000000 ...
08:17:14.22 [25582.210840] 000000004f74b8fd: ffffffffc0b10a00 (zio_reexecute+0x400/0x400 [zfs])
08:17:14.22 [25582.210843] 00000000a3376ec7: ffff91e1d164d580 (0xffff91e1d164d580)
08:17:14.22 [25582.210845] 00000000a04251c2: 0000000000000000 ...
08:17:14.22 [25582.210848] 00000000b9a04c2c: ffffffffffffffff (0xffffffffffffffff)
08:17:14.22 [25582.210851] 000000001c0fa64a: f365ccf157c7f200 (0xf365ccf157c7f200)
08:17:14.22 [25582.210854] 000000001e5333ef: ffff91e275789b40 (0xffff91e275789b40)
08:17:14.22 [25582.210857] 00000000bab5da2f: ffff91e278305e40 (0xffff91e278305e40)
08:17:14.22 [25582.210860] 00000000acdcb118: ffffae7303677a28 (0xffffae7303677a28)
08:17:14.22 [25582.210863] 000000000eba8dad: ffff91e275789660 (0xffff91e275789660)
08:17:14.22 [25582.210866] 000000000471c525: ffff91e14adcdc00 (0xffff91e14adcdc00)
08:17:14.22 [25582.210869] 000000004b25d5fe: ffffae730394ff48 (0xffffae730394ff48)
08:17:14.22 [25582.210961] 0000000000853aa7: ffffffff998acc61 (kthread+0x121/0x140)
08:17:14.22 [25582.210966] 000000005739768d: ffff91e275789b78 (0xffff91e275789b78)
08:17:14.22 [25582.210978] 00000000a2a08794: ffffffffc0885570 (taskq_thread_should_stop+0x70/0x70 [spl])
08:17:14.22 [25582.210985] 00000000d94d83d3: ffffffff998acb40 (kthread_create_worker_on_cpu+0x70/0x70)
08:17:14.22 [25582.210988] 000000008504f7b7: ffff91e278305e40 (0xffff91e278305e40)
08:17:14.22 [25582.210990] 000000006d29eadf: 0000000000000000 ...
08:17:14.22 [25582.210997] 000000000b8764a2: ffffffff9a200205 (ret_from_fork+0x35/0x40)
08:17:14.22 [25582.210998] 00000000dffc02fb: 0000000000000000 ...
08:17:14.22 [26154.004208]  vdb: vdb1 vdb9
08:17:14.22 [26154.024152]  vdb: vdb1 vdb9
08:17:14.22 [26154.191531] Alternate GPT is invalid, using primary GPT.
08:17:14.22 [26154.191541]  vdc: vdc1 vdc9
08:17:14.22 [26154.202631]  vdc: vdc1 vdc9
08:17:14.22 [26154.212522]  vdc: vdc1 vdc9
08:17:14.22 [26154.362975] GPT:disk_guids don't match.
08:17:14.22 [26154.362981] GPT:partition_entry_array_crc32 values don't match: 0x93151696 != 0x41228493
08:17:14.22 [26154.362984] GPT: Use GNU Parted to correct GPT errors.
08:17:14.22 [26154.363004]  vdd: vdd1 vdd9
08:17:14.22 [26154.389964]  vdd: vdd1 vdd9
08:17:14.22 [26759.765450]  vdb: vdb1 vdb9
08:17:14.22 [26759.785214]  vdb: vdb1 vdb9
08:17:14.22 [26759.789805]  vdb: vdb1 vdb9
08:17:14.22 [26759.979244] Alternate GPT is invalid, using primary GPT.
08:17:14.22 [26759.979262]  vdc: vdc1 vdc9
08:17:14.22 [26760.016856]  vdc: vdc1 vdc9
08:17:14.22 [26760.027983]  vdc: vdc1 vdc9
08:17:14.22 [26760.226615] Alternate GPT is invalid, using primary GPT.
08:17:14.22 [26760.226626]  vdd: vdd1 vdd9
08:17:14.22 [26760.235307]  vdd: vdd1 vdd9
08:17:14.22 [26760.245613]  vdd: vdd1 vdd9
08:17:14.22 [27366.589640] GPT:disk_guids don't match.
08:17:14.22 [27366.589643] GPT:partition_entry_array_crc32 values don't match: 0xc96ee0a2 != 0x455233a2
08:17:14.22 [27366.589644] GPT: Use GNU Parted to correct GPT errors.
08:17:14.22 [27366.589652]  vdb: vdb1 vdb9
08:17:14.22 [27366.611732]  vdb: vdb1 vdb9
08:17:14.22 [27366.616521]  vdb: vdb1 vdb9
08:17:14.22 [27366.804712]  vdc: vdc1 vdc9
08:17:14.22 [27366.810259]  vdc: vdc1 vdc9
08:17:14.22 [27366.820049]  vdc: vdc1 vdc9
08:17:14.22 [27367.092109] Alternate GPT is invalid, using primary GPT.
08:17:14.22 [27367.092124]  vdd: vdd1 vdd9
08:17:14.22 [27367.100073]  vdd: vdd1 vdd9
08:17:14.22 [27367.109413]  vdd: vdd1 vdd9
08:17:14.22 [27972.033556] Alternate GPT is invalid, using primary GPT.
08:17:14.22 [27972.033576]  vdb: vdb1 vdb9
08:17:14.22 [27972.050000]  vdb: vdb1 vdb9
08:17:14.22 [27972.054902]  vdb: vdb1 vdb9
08:17:14.22 [27972.236866] Alternate GPT is invalid, using primary GPT.
08:17:14.22 [27972.236911]  vdc: vdc1 vdc9
08:17:14.22 [27972.244964]  vdc: vdc1 vdc9
08:17:14.22 [27972.253086]  vdc: vdc1 vdc9
08:17:14.22 [27972.466664] Alternate GPT is invalid, using primary GPT.
08:17:14.22 [27972.466678]  vdd: vdd1 vdd9
08:17:14.22 [27972.475332]  vdd: vdd1 vdd9
08:17:14.22 [27972.478441]  vdd: vdd1 vdd9
08:17:14.22 [28577.738934] Alternate GPT is invalid, using primary GPT.
08:17:14.22 [28577.738944]  vdb: vdb1 vdb9
08:17:14.22 [28577.754553]  vdb: vdb1 vdb9
08:17:14.22 [28577.908987] GPT:disk_guids don't match.
08:17:14.22 [28577.908990] GPT:partition_entry_array_crc32 values don't match: 0xf0153bd4 != 0xdad3ebfd
08:17:14.22 [28577.908992] GPT: Use GNU Parted to correct GPT errors.
08:17:14.22 [28577.909002]  vdc: vdc1 vdc9
08:17:14.22 [28577.919451]  vdc: vdc1 vdc9
08:17:14.22 [28577.924728]  vdc: vdc1 vdc9
08:17:14.22 [28578.078904] Alternate GPT is invalid, using primary GPT.
08:17:14.22 [28578.078914]  vdd: vdd1 vdd9
08:17:14.22 [28578.092064]  vdd: vdd1 vdd9
08:17:14.22 [29186.248893] Alternate GPT is invalid, using primary GPT.
08:17:14.22 [29186.248909]  vdb: vdb1 vdb9
08:17:14.22 [29186.261383]  vdb: vdb1 vdb9
08:17:14.22 [29186.270441]  vdb: vdb1 vdb9
08:17:14.22 [29186.473070] Alternate GPT is invalid, using primary GPT.
08:17:14.22 [29186.473085]  vdc: vdc1 vdc9
08:17:14.22 [29186.482506]  vdc: vdc1 vdc9
08:17:14.22 [29186.487357]  vdc: vdc1 vdc9
08:17:14.22 [29186.665231] Alternate GPT is invalid, using primary GPT.
08:17:14.22 [29186.665242]  vdd: vdd1 vdd9
08:17:14.22 [29186.673553]  vdd: vdd1 vdd9
08:17:14.22 [29186.692764]  vdd: vdd1 vdd9
08:17:14.22 [29187.698082] Alternate GPT is invalid, using primary GPT.
08:17:14.22 [29187.698102]  vdb: vdb1 vdb9
08:17:14.22 [29187.709172]  vdb: vdb1 vdb9
08:17:14.22 [29187.713707]  vdb: vdb1 vdb9
08:17:14.22 [29187.883832] Alternate GPT is invalid, using primary GPT.
08:17:14.22 [29187.883846]  vdc: vdc1 vdc9
08:17:14.22 [29187.892854]  vdc: vdc1 vdc9
08:17:14.22 [29187.898279]  vdc: vdc1 vdc9
08:17:14.22 [29188.073252] GPT:disk_guids don't match.
08:17:14.22 [29188.073255] GPT:partition_entry_array_crc32 values don't match: 0x9f6da8d2 != 0x594f5246
08:17:14.22 [29188.073256] GPT: Use GNU Parted to correct GPT errors.
08:17:14.22 [29188.073264]  vdd: vdd1 vdd9
08:17:14.22 [29188.093285]  vdd: vdd1 vdd9
08:17:14.22 [34374.788810] Alternate GPT is invalid, using primary GPT.
08:17:14.22 [34374.788820]  vdb: vdb1 vdb9
08:17:14.22 [34374.807607]  vdb: vdb1 vdb9
08:17:14.22 [34374.955861] GPT:disk_guids don't match.
08:17:14.22 [34374.955864] GPT:partition_entry_array_crc32 values don't match: 0x5227ce77 != 0xee607bdd
08:17:14.22 [34374.955866] GPT: Use GNU Parted to correct GPT errors.
08:17:14.22 [34374.955876]  vdc: vdc1 vdc9
08:17:14.22 [34374.986827]  vdc: vdc1 vdc9
08:17:14.22 [34375.147486] GPT:disk_guids don't match.
08:17:14.22 [34375.147489] GPT:partition_entry_array_crc32 values don't match: 0xf58fc1bb != 0x9f6da8d2
08:17:14.22 [34375.147490] GPT: Use GNU Parted to correct GPT errors.
08:17:14.22 [34375.147499]  vdd: vdd1 vdd9
08:17:14.22 [34375.172525]  vdd: vdd1 vdd9
08:17:14.22 [34376.556208] GPT:disk_guids don't match.
08:17:14.22 [34376.556215] GPT:partition_entry_array_crc32 values don't match: 0xe1c34f5e != 0x6e24ab17
08:17:14.22 [34376.556217] GPT: Use GNU Parted to correct GPT errors.
08:17:14.22 [34376.556237]  vdb: vdb1 vdb9
08:17:14.22 [34376.574947]  vdb: vdb1 vdb9
08:17:14.22 [34376.740212] GPT:disk_guids don't match.
08:17:14.22 [34376.740221] GPT:partition_entry_array_crc32 values don't match: 0x56a574e0 != 0x5227ce77
08:17:14.22 [34376.740224] GPT: Use GNU Parted to correct GPT errors.
08:17:14.22 [34376.740249]  vdc: vdc1 vdc9
08:17:14.22 [34376.752590]  vdc: vdc1 vdc9
08:17:14.22 [34376.762574]  vdc: vdc1 vdc9
08:17:14.22 [34377.363255] GPT:disk_guids don't match.
08:17:14.22 [34377.363259] GPT:partition_entry_array_crc32 values don't match: 0x383a74b4 != 0xf58fc1bb
08:17:14.22 [34377.363261] GPT: Use GNU Parted to correct GPT errors.
08:17:14.22 [34377.363275]  vdd: vdd1 vdd9
08:17:14.22 [34377.379104]  vdd: vdd1 vdd9
08:17:14.22 [34377.382936]  vdd: vdd1 vdd9
08:17:14.22 [36793.137798] Alternate GPT is invalid, using primary GPT.
08:17:14.22 [36793.137809]  vdb: vdb1 vdb9
08:17:14.22 [36793.147471]  vdb: vdb1 vdb9
08:17:14.22 [36793.302885] Alternate GPT is invalid, using primary GPT.
08:17:14.22 [36793.302898]  vdc: vdc1 vdc9
08:17:14.22 [36793.311353]  vdc: vdc1 vdc9
08:17:14.22 [36793.314010]  vdc: vdc1 vdc9
08:17:14.22 [36793.468023] GPT:disk_guids don't match.
08:17:14.22 [36793.468035] GPT:partition_entry_array_crc32 values don't match: 0xc7fe383c != 0x383a74b4
08:17:14.22 [36793.468036] GPT: Use GNU Parted to correct GPT errors.
08:17:14.22 [36793.468046]  vdd: vdd1 vdd9
08:17:14.22 [36793.480494]  vdd: vdd1 vdd9
08:17:14.22 [36793.482698]  vdd: vdd1 vdd9
08:17:14.22 [36794.251067] GPT:disk_guids don't match.
08:17:14.22 [36794.251070] GPT:partition_entry_array_crc32 values don't match: 0x253de26a != 0x86caeb47
08:17:14.22 [36794.251071] GPT: Use GNU Parted to correct GPT errors.
08:17:14.22 [36794.251081]  vdb: vdb1 vdb9
08:17:14.22 [36794.267623]  vdb: vdb1 vdb9
08:17:14.22 [36794.402740] GPT:disk_guids don't match.
08:17:14.22 [36794.402744] GPT:partition_entry_array_crc32 values don't match: 0xa7c0f135 != 0xf5bea68
08:17:14.22 [36794.402746] GPT: Use GNU Parted to correct GPT errors.
08:17:14.22 [36794.402757]  vdc: vdc1 vdc9
08:17:14.22 [36794.418592]  vdc: vdc1 vdc9
08:17:14.22 [36794.557249] GPT:disk_guids don't match.
08:17:14.22 [36794.557251] GPT:partition_entry_array_crc32 values don't match: 0xd810763f != 0xc7fe383c
08:17:14.22 [36794.557252] GPT: Use GNU Parted to correct GPT errors.
08:17:14.22 [36794.557259]  vdd: vdd1 vdd9
08:17:14.22 [36794.566589]  vdd: vdd1 vdd9
08:17:14.22 [39209.039972] Alternate GPT is invalid, using primary GPT.
08:17:14.22 [39209.039993]  vdb: vdb1 vdb9
08:17:14.22 [39209.050469]  vdb: vdb1 vdb9
08:17:14.22 [39209.058998]  vdb: vdb1 vdb9
08:17:14.22 [39209.241037] Alternate GPT is invalid, using primary GPT.
08:17:14.22 [39209.241047]  vdc: vdc1 vdc9
08:17:14.22 [39209.251216]  vdc: vdc1 vdc9
08:17:14.22 [39209.254529]  vdc: vdc1 vdc9
08:17:14.22 [39209.414704] Alternate GPT is invalid, using primary GPT.
08:17:14.22 [39209.414716]  vdd: vdd1 vdd9
08:17:14.22 [39209.422989]  vdd: vdd1 vdd9
08:17:14.22 [39209.429023]  vdd: vdd1 vdd9
08:17:14.22 [39210.481895]  vdb: vdb1 vdb9
08:17:14.22 [39210.499125]  vdb: vdb1 vdb9
08:17:14.22 [39210.660441] GPT:disk_guids don't match.
08:17:14.22 [39210.660447] GPT:partition_entry_array_crc32 values don't match: 0x7edb9f5 != 0x272cea0a
08:17:14.22 [39210.660449] GPT: Use GNU Parted to correct GPT errors.
08:17:14.22 [39210.660465]  vdc: vdc1 vdc9
08:17:14.22 [39210.670617]  vdc: vdc1 vdc9
08:17:14.22 [39210.675929]  vdc: vdc1 vdc9
08:17:14.22 [39210.826918] Alternate GPT is invalid, using primary GPT.
08:17:14.22 [39210.826930]  vdd: vdd1 vdd9
08:17:14.22 [39210.835376]  vdd: vdd1 vdd9
08:17:14.22 [39210.840074]  vdd: vdd1 vdd9
08:17:14.22 =================================================================
08:17:14.22  End of dmesg log
08:17:14.22 =================================================================
08:17:14.22 NOTE: Performing test-fail callback (/var/lib/buildbot/slaves/buildslave1/Ubuntu_18_04_x86_64__PERF_/build/zfs/tests/zfs-tests/callbacks/zfs_mmp.ksh)
08:17:14.23 NOTE: Performing local cleanup via log_onexit (cleanup)
08:17:14.34 removed all registered handlers
08:17:14.35 SUCCESS: zinject -c all
08:17:14.85 SUCCESS: zpool destroy -f perfpool
08:17:15.78 SUCCESS: zpool create -f perfpool virtio-D00 virtio-D01 virtio-D02
jwk404 commented 6 years ago

@gmelikov How big are the disks in this rig?

gmelikov commented 6 years ago

@jwk404 they must be 4G: TEST_ZFSTESTS_DISKSIZE=4G

tonynguien commented 6 years ago

@gmelikov - What's the total system memory? From what I can tell, dbuf test allocates data up to 75% of dbuf size and each file is that total / 64 (job count). So perhaps, it's creating < 1M files.

On Sun, Jul 1, 2018 at 9:11 AM George Melikov notifications@github.com wrote:

@jwk404 https://github.com/jwk404 they must be 4G: TEST_ZFSTESTS_DISKSIZE=4G

— You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub https://github.com/zfsonlinux/zfs/issues/7666#issuecomment-401612853, or mute the thread https://github.com/notifications/unsubscribe-auth/ACFa_IJHU2mJCAYxkwpf_ZqNg25kN9tKks5uCOaUgaJpZM4U8jED .

behlendorf commented 6 years ago

The VM doesn't have a ton of memory, or particularly fast disk or large disks. I'll see about migrating it to a more capable machine this week.

stale[bot] commented 4 years ago

This issue has been automatically marked as "stale" because it has not had any activity for a while. It will be closed in 90 days if no further activity occurs. Thank you for your contributions.