Merge pull request #314 from gonzoleeman/improve-python-selftest-v2

Improve python selftest

6 files changed, 418 insertions, 131 deletions

diff --git a/test/.setup b/test/.setup
deleted file mode 100644
index cfa31b4..0000000
--- a/test/.setup
+++ /dev/null
@@ -1,3 +0,0 @@
-target="iqn.2003-01.org.linux-iscsi.linux-dell.x8664:sn.ae8d5828b4b4"
-ipnr="192.168.20.3:3260"
-dev="/dev/sdb"
diff --git a/test/README b/test/README
index af54c3c..c98175a 100644
--- a/test/README
+++ b/test/README
@@ -1,93 +1,239 @@
-From the original test/README:
 ---------------------------------------------------------------------------
-This directory contains regression suite.
 
-I would appreciate if developer will run it at least once after
-modifications done before commit or mailing list submit.
+======
+README
+======
+
+--------------------
+Setting up the tests
+--------------------
+
+  This is the README for the updated "test" open-iscsi subdirectory.
+
+  Note that these tests are *not* performance tests. So no
+  attempt is made to track or display how long each test takes,
+  so it is not currently possible to track any improvement
+  nor degredation in IO performance. Please feel free to
+  add tests to measure performance, if you wish.
+
+  The tests here are based on the python unittest package. Please use
+  the included "test-open-iscsi.py" python script to run the tests.
+  You can run:
+
+    # ./test-open-iscsi.py --help
+
+  to get a list of options for this script. You will need the following
+  packages or commands to run these tests:
+
+  * fio
+  * bonie++
+  * mkfs.FSTYPE (e.g. mkfs.ext3)
+  * sgdisk
+  * dd
+  * parted
+  * mount/umount
+  * iscsiadm (with the iscsid daemon or service running) [of course]
+
+
+-----------------
+Running the tests
+-----------------
+
+  You will also need to know the IQN (name) of an accesable iscsi target,
+  set up with appropriate access controls so that you can log into it,
+  as well as the IP address where you can access this
+  target, and you will need to know which SCSI disk will show in in
+  /dev for this target (e.g. "/dev/sdc", if you already have a "/dev/sda"
+  and a "/dev/sdb"). You will need to pass in this information to the
+  python script to test. For example, to run all tests on my test
+  system (as root, of course):
+
+    # ./test-open-iscsi.py -v -f \
+        -t iqn.2003-01.org.linux-iscsi.linux-o2br.x8664:sn.2296be998e2c \
+	-i 192.168.20.168 \
+	-D /dev/sdc
+
+  This can take quite a while to run -- hours -- unless you limit
+  the tests to a subset of the whole suite.
+
+  The data on your target iSCSI disc will be wiped, so don't use a target
+  that has data you wish to save. As far as the size of the target, I
+  set up a 10G block-based iscsi target. Having a larger target makes
+  the test run take longer, though. I believe 1G or even 100M might work?
+
+  Instead of running all the tests, one can instead run a subtest, since
+  the unittest package supports this. To get a list of the tests, run:
+
+    # ./test-open-iscsi.py -l
+    test_HdrDigest_on_DataDigest_off (harness.tests.TestRegression)
+    test_HdrDigest_on_DataDigest_on (harness.tests.TestRegression)
+    test_InitialR2T_off_ImmediateData_off (harness.tests.TestRegression)
+    test_InitialR2T_off_ImmediateData_on (harness.tests.TestRegression)
+    test_InitialR2T_on_ImmediateData_off (harness.tests.TestRegression)
+    test_InitialR2T_on_ImmediateData_on (harness.tests.TestRegression)
 
-./regression.sh script expects next binaries and data files exists
-in current directory:
+  I believe the names are self-explanitory. (If not, submit a pull
+  request or let me know.)
 
-	- regression.dat
-	- iscsiadm
-	- bonnie++ (source: http://www.open-iscsi.org/bits/bonnie++.tar.gz)
-	- disktest (source: http://www.open-iscsi.org/bits/disktest.tar.gz)
+  There are 6 test groups, all coming from one test script file (in
+  harness/tests.py), and that are in the the TestRegression python class.
 
-Thanks!
-Dmitry
----------------------------------------------------------------------------
-Call:
-
-> # ./regression.sh -f/--format <device>
-
-to run "mkfs" on the device and exit, or
-
-> # ./regression.sh <targetname> <ipnumber#> <device> [test#[:#]] [bsize]
-
-Where:
-	<targetname>	?
-	<ipnumber#>	?
-	<device>	the device on which to test (e.g. /dev/sd?)
-	test#[:#]	test(s) to run, i.e. single or range (default: all)
-	bsize		disktest block size (default: a range of 10 sizes)
-			special value "bonnie" => skip disktest
-
-And env var "SKIP_WARNING" skips a big warning about writing on the device?
-
----------------------------------------------------------------------------
+  [In the future, one can add more tests to this class, and other
+  classes to test things besides regression (like functionality,
+  bug-fix detection, etc).]
 
-The problem is that these tests have not been run for a while, and,
-additionally, disktest seems to be extinct and unfindable.
+  See below for an exapmle of how you might use this option.
 
-I plan to get these tests working, and consider these the steps I plan
-to take:
+  One can also specify the list of subtests (by number) for each test,
+  further reducing test executing amount and time, if one wishes, using
+  the "-l/--list" option. Each subtest specifies a different
+  combination of FirstBurst, MaxBurstLength, and MaxRecv for the IO test.
+  Here's a list of the subest values:
 
-* understand the current tests
-  - particularly, what disktest and bonnie++ are doing
+    Subtest   [FirstBurstLength, MaxBurstLength, MaxRecvDataSegmentLength]
+        1	    4096	     4096	     4096
+        2	    8192	     4096	     4096
+        3	   16384	     4096	     4096
+        4	   32768	     4096	     4096
+        5	   65536	     4096	     4096
+        6	  131972	     4096	     4096
+        7	    4096	     8192	     4096
+        8	    4096	    16384	     4096
+        9	    4096	    32768	     4096
+       10	    4096	    65536	     4096
+       11	    4096	   131072	     4096
+       12	    4096	     4096	     8192
+       13	    4096	     4096	    16384
+       14	    4096	     4096	    32768
+       15	    4096	     4096	    65536
+       16	    4096	     4096	   131072
+
+  So to run subtest 7 through 11 of test_InitialR2T_off_ImmediateData_off:
+
+    # ... (fill in)									<< TODO XXX
+
+  Lastly, one can reduce the number of tests run (and hence the length of
+  time spent testing) by specifying the block size to test with during
+  IO testing. By default the script uses an array of block sizes:
+
+	[512,1k,2k,4k,8k,16k,32k,75536,128k,1000000]
+
+  For example, to run a test for block size 4k, all subtest 12, for
+  the test_HdrDigest_on_DataDigest_on test:
+
+    # ./test-open-iscsi.py -v -f \
+        -t iqn.2003-01.org.linux-iscsi.linux-o2br.x8664:sn.2296be998e2c \
+	-i 192.168.20.168 \
+	-D /dev/sdc \
+	-B 4k \
+	-s 12 \
+	TestRegression.test_HdrDigest_on_DataDigest_on
+
+
+------------------
+Test Descriptsions
+------------------
+
+  The "regression" test sequence was laid out in regression.sh (the
+  previous test script, still around for reference). I am not sure
+  why we still call it a regression test, when it does not in fact
+  check for any regression in performance. Instead, it tests
+  functionality.
+
+  Each iscsi test has the following default values
+  (called "IscsiData()" in the test suite). These correspond to
+  the default values usually found in open-iscsi:
+
+    Immediate Data		= on
+    Initial Request to Transmit	= off
+    Header Digest		= 'None,CRC32C' (i.e. off by default)
+    Data Digest			= 'None,CRC32C' (i.e. off by default)
+    First Burst Length		= 256k
+    Max Burst Length		= (16 Meg - 1k)
+    Max Receive Data Length	= 128k
+    Max Request to Transmit	= 1
+
+  but one or more of these values can be overwritten for each test.
+
+  The current test suite is laid out like this:
+
+    test_HdrDigest_on_DataDigest_off (harness.tests.TestRegression)
+
+	This tests the Header Digest functionality, by itself.
+
+    test_HdrDigest_on_DataDigest_on (harness.tests.TestRegression)
+
+	This one tests both the Header and Data Digest functionality,
+	together
+
+    test_InitialR2T_off_ImmediateData_off (harness.tests.TestRegression)
+
+	Test both Initial Rquest to Transmit and Imediate data off
+
+    test_InitialR2T_off_ImmediateData_on (harness.tests.TestRegression)
+
+	Test with Initial Request to Transmit off but Imeediate Data
+	on. (This is the default configuration)
+
+    test_InitialR2T_on_ImmediateData_off (harness.tests.TestRegression)
+
+	Test Initial Request to Transmit on but Imediate Data off
+
+    test_InitialR2T_on_ImmediateData_on (harness.tests.TestRegression)
+
+	Test with both Initial Request to Transmit and Immediate Data
+	on.
+
+  For each test run (from this list above), we perform the following tests:
+
+    - Use "iscsiadm" to log into the iscsi target and wait for the
+      device to show up
+    - Run "fio" on the raw disc device
+	This is done 16 times, one for each subtest (see above)
+	  Each of these 16 tests has 10 different block sizes used
+	  (see above)
+	  fio actually does (for each block size):
+	  - fio read test (8 threads)
+	  - fio write test (8 threads)
+	  - fio verify test (1 thread)
+    - Run "parted" to partition
+	This actually first runs "sgdisk" then "dd" to wipe the disc,
+	then runs "parted" make a label then partition it, then
+	waits for the partition to show up.
+    - Run "mkfs" to create a filesystem (EXT3 by default)
+    - Run "bonnie++" on the created filesystem
 
-* try to replace disktest and/or bonnie++, if needed
-  - there are a lot of good disk test packages these days
+  For the math-friendly out there, I believe this adds up to about
+  960 tests (10x16x6). By far the slowest part of the tests seems
+  to be wiping the discs clean of a label or partitions. Perhaps this
+  can be sped up?
 
-* replace the shell code with PyTest code, to make it
-  easier to use
+  The following things can be overridden in the environment, if you
+  wish, by setting the appropriate environment variable before running
+  the test script:
 
-Lee Duncan -- 2/13/2020
+    env. var.		default			meaning
+    ---------		-------			-------
+    FSTYPE		"ext3"			filesystem type to create
+    MOUNTOPTIONS	"-t FSTYPE"		"-t FSTYPE" is added to whatever
+						options you pass in, if any
+    MKFSCMD		"mkfs.FSTYPE"		which mkfs command to call
+    MKFSOPTS		<none>			options too add to mkfs call,
+						if any
+    BONNIEPARAMS	"-r0 -n10:0:0 -s16 -uroot -f -q"
+						params used when running bonnie++
 
-Analysis of disktest usage:
+-----------------------------------
+Suggestions for running these tests
+-----------------------------------
 
-	options used:					fio option for this?
-	=======================================		==================================
-							--name=test (or whatever)
-	-T2		-- run 2 seconds		--runtime=2
-	-K8		-- run with 8 threads		--numjobs=8
-	-B<bs>		-- set block xfer size		--blocksize=<bs> (default 4k?)
-	-ID		-- use direct IO		--direct=1
-	<dev>		-- use device			--filename=<dev>
+  I suggest the following values for setting up these tests:
 
-	in read mode:
-	-r		-- read mode			--readwrite=randread
+  - Set up a smaller target -- maybe 100M -- which makes tests run faster
+  - Ensure that noop_out_* values are 0 (NOPs off) for your target
+  - Use the local system for your target, to avoid network/switch delays
+  - If there are failures, check dmesg for possible error messages
+  - If you use targetcli for your target, disable NOP-INs on the
+    target ACL attributes
 
-	in write mode:
-	-w		-- write mode			--readwrite=randwrite
-	-E 16		-- compare 16 bytes		--verify=md5? (lots of options)
-
-It looks like the "fio" program may address these needs?
-
-e.g. running
-
-with file "test.fio":
-> [test]
-> rw=randread
-> bs=8k
-> filename=/dev/sdb
-> direct=1
-> numjobs=4
-> runtime=60s
-
-run:
-
-> # fio test.fio
-
-The output is interactive? But results are ridiculously verbose,
-but include a nice summary line or two that could be used as a
-go/no-go?
+---------------------------------------------------------------------------
diff --git a/test/README.orig b/test/README.orig
new file mode 100644
index 0000000..a046b01
--- /dev/null
+++ b/test/README.orig
@@ -0,0 +1,104 @@
+---------------------------------------------------------------------------
+A Note from current open-iscsi maintainer Lee Duncan:
+
+README.orig:
+  This is the old README for the "test" subdirectory, directed
+  at being able to use the "regressioin..sh" shell script. But
+  I no longer maintain the shell script, much preferring the
+  python unittest package. Please see the new README file
+  for how to use that package. (2/2022)
+---------------------------------------------------------------------------
+
+From the original test/README:
+---------------------------------------------------------------------------
+This directory contains regression suite.
+
+I would appreciate if developer will run it at least once after
+modifications done before commit or mailing list submit.
+
+./regression.sh script expects next binaries and data files exists
+in current directory:
+
+	- regression.dat
+	- iscsiadm
+	- bonnie++ (source: http://www.open-iscsi.org/bits/bonnie++.tar.gz)
+	- disktest (source: http://www.open-iscsi.org/bits/disktest.tar.gz)
+
+Thanks!
+Dmitry
+---------------------------------------------------------------------------
+Call:
+
+> # ./regression.sh -f/--format <device>
+
+to run "mkfs" on the device and exit, or
+
+> # ./regression.sh <targetname> <ipnumber#> <device> [test#[:#]] [bsize]
+
+Where:
+	<targetname>	?
+	<ipnumber#>	?
+	<device>	the device on which to test (e.g. /dev/sd?)
+	test#[:#]	test(s) to run, i.e. single or range (default: all)
+	bsize		disktest block size (default: a range of 10 sizes)
+			special value "bonnie" => skip disktest
+
+And env var "SKIP_WARNING" skips a big warning about writing on the device?
+
+---------------------------------------------------------------------------
+
+The problem is that these tests have not been run for a while, and,
+additionally, disktest seems to be extinct and unfindable.
+
+I plan to get these tests working, and consider these the steps I plan
+to take:
+
+* understand the current tests
+  - particularly, what disktest and bonnie++ are doing
+
+* try to replace disktest and/or bonnie++, if needed
+  - there are a lot of good disk test packages these days
+
+* replace the shell code with PyTest code, to make it
+  easier to use
+
+Lee Duncan -- 2/13/2020
+
+Analysis of disktest usage:
+
+	options used:					fio option for this?
+	=======================================		==================================
+							--name=test (or whatever)
+	-T2		-- run 2 seconds		--runtime=2
+	-K8		-- run with 8 threads		--numjobs=8
+	-B<bs>		-- set block xfer size		--blocksize=<bs> (default 4k?)
+	-ID		-- use direct IO		--direct=1
+	<dev>		-- use device			--filename=<dev>
+
+	in read mode:
+	-r		-- read mode			--readwrite=randread
+
+	in write mode:
+	-w		-- write mode			--readwrite=randwrite
+	-E 16		-- compare 16 bytes		--verify=md5? (lots of options)
+
+It looks like the "fio" program may address these needs?
+
+e.g. running
+
+with file "test.fio":
+> [test]
+> rw=randread
+> bs=8k
+> filename=/dev/sdb
+> direct=1
+> numjobs=4
+> runtime=60s
+
+run:
+
+> # fio test.fio
+
+The output is interactive? But results are ridiculously verbose,
+but include a nice summary line or two that could be used as a
+go/no-go?
diff --git a/test/TODO b/test/TODO
index 096f250..d53f0c9 100644
--- a/test/TODO
+++ b/test/TODO
@@ -2,14 +2,6 @@
 # Things to do for testing
 #
 
-* get current tests running
-  * this will mean replacing disktest with something
-    (like fio?)
-
-  PASS -- no need to spend time getting disktest working
-  when (1) it's hard to find, and (2) it's going to be
-  replaced anyway.
-
 * ensure user is root? -- easy to do
 
 * have tests create their own target using targetcli and
@@ -21,9 +13,6 @@
   that to be done already. Either way, we may still need
   to know the IQN of our target and the host where it lives.
 
-  PASS -- we still would have to know two things (IQN and
-  IP:Port). See next item.
-
 * Have tests figure out the device path, so it doesn't have
   to be passed in. Passing it in requires the called to
   login to the remote iscsi target and look at the path
@@ -58,11 +47,13 @@
 
 * Add back in the "big warning" from regression.sh?
 
-* Add info to the README about how to run the python tests
+* Find a faster way to zero the disc than using sgdisk and
+  dd. Running both of these on a 10G disc can take minutes.
 
-* Leave the regression test around, for now? It doesn't run,
-  so maybe it should just be removed?
+* Come up with some common subsets of tests that can be run
+  when needed, since running all the tests takes forever. Maybe
+  a "short", "medium", and "long" option, so the caller doesn't
+  have to remember the arcane command-line options?
 
-* Add in option to specify which subtests (of 16) are run
-  for each test case. Would make it much faster for testing
-  and go/no-go testing?
+* keep track of our session id (when we have one), so that
+  we can log out of just our session more easily
diff --git a/test/harness/tests.py b/test/harness/tests.py
index 7833aac..224f216 100644
--- a/test/harness/tests.py
+++ b/test/harness/tests.py
@@ -18,7 +18,7 @@ class TestRegression(unittest.TestCase):
 
     @classmethod
     def setUpClass(cls):
-        util.verify_needed_commands_exist(['parted', 'fio', 'mkfs', 'bonnie++', 'sgdisk', 'iscsiadm'])
+        util.verify_needed_commands_exist(['parted', 'fio', Global.MKFSCMD[0], 'bonnie++', 'sgdisk', 'iscsiadm'])
         util.vprint('*** Starting %s' % cls.__name__)
         # XXX validate that target exists?
         # an array of first burts, max burst, and max recv values, for testing
@@ -57,11 +57,11 @@ class TestRegression(unittest.TestCase):
         """Test Initial Request to Transmit on, but Immediate Data off"""
         i = 1
         for v in self.param_values:
-            with self.subTest('Testing FirstBurst={} MaxBurts={} MaxRecv={}'.format(*v), i=i):
+            with self.subTest('Testing FirstBurst={} MaxBurst={} MaxRecv={}'.format(*v), i=i):
                 if i not in Global.subtest_list:
-                    util.vprint('Skipping subtest %d: FirstBurst={} MaxBurts={} MaxRecv={}'.format(*v) % i)
+                    util.vprint('Skipping subtest %d: FirstBurst={} MaxBurst={} MaxRecv={}'.format(*v) % i)
                 else:
-                    util.vprint('Running subtest %d: FirstBurst={} MaxBurts={} MaxRecv={}'.format(*v) % i)
+                    util.vprint('Running subtest %d: FirstBurst={} MaxBurst={} MaxRecv={}'.format(*v) % i)
                     self.iscsi_logout()
                     iscsi_data = IscsiData('No', 'Yes', 'None', 'None', v[0], v[1], v[2])
                     iscsi_data.update_cfg(Global.target, Global.ipnr)
@@ -72,10 +72,11 @@ class TestRegression(unittest.TestCase):
         """Test Initial Request to Transmit off, Immediate Data on"""
         i = 1
         for v in self.param_values:
-            with self.subTest('Testing FirstBurst={} MaxBurts={} MaxRecv={}'.format(*v), i=i):
+            with self.subTest('Testing FirstBurst={} MaxBurst={} MaxRecv={}'.format(*v), i=i):
                 if i not in Global.subtest_list:
-                    util.vprint('Skipping subtest %d: FirstBurst={} MaxBurts={} MaxRecv={}'.format(*v) % i)
+                    util.vprint('Skipping subtest %d: FirstBurst={} MaxBurst={} MaxRecv={}'.format(*v) % i)
                 else:
+                    util.vprint('Running subtest %d: FirstBurst={} MaxBurst={} MaxRecv={}'.format(*v) % i)
                     self.iscsi_logout()
                     iscsi_data = IscsiData('Yes', 'No', 'None', 'None', v[0], v[1], v[2])
                     iscsi_data.update_cfg(Global.target, Global.ipnr)
@@ -86,11 +87,11 @@ class TestRegression(unittest.TestCase):
         """Test Initial Request to Transmit and Immediate Data on"""
         i = 1
         for v in self.param_values:
-            with self.subTest('Testing FirstBurst={} MaxBurts={} MaxRecv={}'.format(*v), i=i):
+            with self.subTest('Testing FirstBurst={} MaxBurst={} MaxRecv={}'.format(*v), i=i):
                 if i not in Global.subtest_list:
-                    util.vprint('Skipping subtest %d: FirstBurst={} MaxBurts={} MaxRecv={}'.format(*v) % i)
+                    util.vprint('Skipping subtest %d: FirstBurst={} MaxBurst={} MaxRecv={}'.format(*v) % i)
                 else:
-                    util.vprint('Running subtest %d: FirstBurst={} MaxBurts={} MaxRecv={}'.format(*v) % i)
+                    util.vprint('Running subtest %d: FirstBurst={} MaxBurst={} MaxRecv={}'.format(*v) % i)
                     self.iscsi_logout()
                     iscsi_data = IscsiData('Yes', 'Yes', 'None', 'None', v[0], v[1], v[2])
                     iscsi_data.update_cfg(Global.target, Global.ipnr)
@@ -101,11 +102,11 @@ class TestRegression(unittest.TestCase):
         """Test Initial Request to Transmit and Immediate Data off"""
         i = 1
         for v in self.param_values:
-            with self.subTest('Testing FirstBurst={} MaxBurts={} MaxRecv={}'.format(*v), i=i):
+            with self.subTest('Testing FirstBurst={} MaxBurst={} MaxRecv={}'.format(*v), i=i):
                 if i not in Global.subtest_list:
-                    util.vprint('Skipping subtest %d: FirstBurst={} MaxBurts={} MaxRecv={}'.format(*v) % i)
+                    util.vprint('Skipping subtest %d: FirstBurst={} MaxBurst={} MaxRecv={}'.format(*v) % i)
                 else:
-                    util.vprint('Running subtest %d: FirstBurst={} MaxBurts={} MaxRecv={}'.format(*v) % i)
+                    util.vprint('Running subtest %d: FirstBurst={} MaxBurst={} MaxRecv={}'.format(*v) % i)
                     self.iscsi_logout()
                     iscsi_data = IscsiData('No', 'No', 'None', 'None', v[0], v[1], v[2])
                     iscsi_data.update_cfg(Global.target, Global.ipnr)
@@ -116,11 +117,11 @@ class TestRegression(unittest.TestCase):
         """Test With Header Digest"""
         i = 1
         for v in self.param_values:
-            with self.subTest('Testing FirstBurst={} MaxBurts={} MaxRecv={}'.format(*v), i=i):
+            with self.subTest('Testing FirstBurst={} MaxBurst={} MaxRecv={}'.format(*v), i=i):
                 if i not in Global.subtest_list:
-                    util.vprint('Skipping subtest %d: FirstBurst={} MaxBurts={} MaxRecv={}'.format(*v) % i)
+                    util.vprint('Skipping subtest %d: FirstBurst={} MaxBurst={} MaxRecv={}'.format(*v) % i)
                 else:
-                    util.vprint('Running subtest %d: FirstBurst={} MaxBurts={} MaxRecv={}'.format(*v) % i)
+                    util.vprint('Running subtest %d: FirstBurst={} MaxBurst={} MaxRecv={}'.format(*v) % i)
                     self.iscsi_logout()
                     iscsi_data = IscsiData('No', 'Yes', 'CRC32C', 'None', v[0], v[1], v[2])
                     iscsi_data.update_cfg(Global.target, Global.ipnr)
@@ -131,11 +132,11 @@ class TestRegression(unittest.TestCase):
         """Test With Header Digest"""
         i = 1
         for v in self.param_values:
-            with self.subTest('Testing FirstBurst={} MaxBurts={} MaxRecv={}'.format(*v), i=i):
+            with self.subTest('Testing FirstBurst={} MaxBurst={} MaxRecv={}'.format(*v), i=i):
                 if i not in Global.subtest_list:
-                    util.vprint('Skipping subtest %d: FirstBurst={} MaxBurts={} MaxRecv={}'.format(*v) % i)
+                    util.vprint('Skipping subtest %d: FirstBurst={} MaxBurst={} MaxRecv={}'.format(*v) % i)
                 else:
-                    util.vprint('Running subtest %d: FirstBurst={} MaxBurts={} MaxRecv={}'.format(*v) % i)
+                    util.vprint('Running subtest %d: FirstBurst={} MaxBurst={} MaxRecv={}'.format(*v) % i)
                     self.iscsi_logout()
                     iscsi_data = IscsiData('No', 'Yes', 'CRC32C', 'CRC32C', v[0], v[1], v[2])
                     iscsi_data.update_cfg(Global.target, Global.ipnr)
@@ -151,12 +152,18 @@ class TestRegression(unittest.TestCase):
         # wait a few seconds for the device to show up
         if not util.wait_for_path(Global.device):
             self.fail('%s: does not exist after login' % Global.device)
-        (res, reason) = util.run_fio()
-        self.assertEqual(res, 0, reason)
+        # run parted to partition the disc with one whole disk partition
         (res, reason) = util.run_parted()
         self.assertEqual(res, 0, reason)
+        # run fio to test file IO
+        (res, reason) = util.run_fio()
+        self.assertEqual(res, 0, reason)
+        # wait a bit for cache to flush
+        util.sleep_some(1)
+        # make a filesystem
         (res, reason) = util.run_mkfs()
         self.assertEqual(res, 0, reason)
+        # run bonnie++ to test the filesystem IO
         (res, reason) = util.run_bonnie()
         self.assertEqual(res, 0, reason)
 
@@ -170,4 +177,7 @@ class TestRegression(unittest.TestCase):
                       '-T', Global.target,
                       '-p', Global.ipnr,
                       '--logout'])
+        util.vprint("Times: fio=%-.3f, sgdisk=%-.3f, dd=%-.3f, bonnie=%-.3f, mkfs=%-.3f, sleep=%-.3f" % \
+                (Global.fio_time, Global.sgdisk_time, Global.dd_time, \
+                 Global.bonnie_time, Global.mkfs_time, Global.sleep_time))
 
diff --git a/test/harness/util.py b/test/harness/util.py
index d2a7b63..d7c64a2 100644
--- a/test/harness/util.py
+++ b/test/harness/util.py
@@ -42,6 +42,13 @@ class Global:
     # XXX we should really look how many subtests there are, but there's
     # no good way to detect that.
     subtest_list = [i+1 for i in range(16)]
+    # for timing
+    fio_time = 0.0
+    sgdisk_time = 0.0
+    dd_time = 0.0
+    bonnie_time = 0.0
+    mkfs_time = 0.0
+    sleep_time = 0.0
 
 
 def dprint(*args):
@@ -261,7 +268,7 @@ def run_fio():
     Return zero for success.
     Return non-zero for failure and a failure reason.
 
-    Uses Globals: device, blocksize
+    Uses Globals: partition, blocksize
     """
     if Global.blocksize is not None:
         dprint('Found a block size passed in: %s' % Global.blocksize)
@@ -272,37 +279,41 @@ def run_fio():
                 '16k', '32k', '75536', '128k', '1000000']
     # for each block size, do a read test, then a write test
     for bs in blocksizes:
-        vprint('Running "fio" read test: 8 threads, bs=%s' % bs)
+        vprint('Running "fio" read/write/verify tests with 8/8/1 threads, bs=%s' % bs)
         # only support direct IO with aligned reads
         if bs.endswith('k'):
             direct=1
         else:
             direct=0
+        ts = time.time()
         res = run_cmd(['fio', '--name=read-test', '--readwrite=randread',
             '--runtime=2s', '--numjobs=8', '--blocksize=%s' % bs, 
-            '--direct=%d' % direct, '--filename=%s' % Global.device])
+            '--offset=256k',
+            '--direct=%d' % direct, '--filename=%s' % Global.partition])
         if res != 0:
             return (res, 'fio failed')
-        vprint('Running "fio" write test: 8 threads, bs=%s' % bs)
         res = run_cmd(['fio', '--name=write-test', '--readwrite=randwrite',
             '--runtime=2s', '--numjobs=8', '--blocksize=%s' % bs, 
-            '--direct=%d' % direct, '--filename=%s' % Global.device])
+            '--offset=256k',
+            '--direct=%d' % direct, '--filename=%s' % Global.partition])
         if res != 0:
             return (res, 'fio failed')
-        vprint('Running "fio" verify test: 1 thread, bs=%s' % bs)
         res = run_cmd(['fio', '--name=verify-test', '--readwrite=randwrite',
             '--runtime=2s', '--numjobs=1', '--blocksize=%s' % bs, 
-            '--direct=%d' % direct, '--filename=%s' % Global.device,
+            '--direct=%d' % direct, '--filename=%s' % Global.partition,
+            '--offset=256k',
             '--verify=md5', '--verify_state_save=0'])
         if res != 0:
             return (res, 'fio failed')
+        te = time.time()
+        Global.fio_time += (te - ts)
     return (0, 'Success')
 
 def wait_for_path(path, present=True, amt=10):
     """Wait until a path exists or is gone"""
     dprint("Looking for path=%s, present=%s" % (path, present))
     for i in range(amt):
-        time.sleep(1)
+        sleep_some(1)
         if os.path.exists(path) == present:
             dprint("We are Happy :) present=%s, cnt=%d" % (present, i))
             return True
@@ -318,13 +329,27 @@ def wipe_disc():
     """
     # zero out the label and parition table
     vprint('Running "sgdisk" and "dd" to wipe disc label, partitions, and filesystem')
-    time.sleep(1)
-    res = run_cmd(['sgdisk', '-Z', Global.device])
+    sleep_some(1)
+    ts = time.time()
+    res = run_cmd(['sgdisk', '--clear', Global.device])
+    te = time.time()
+    Global.sgdisk_time += (te - ts)
     if res != 0:
-        return (res, '%s: could not zero out label: %d' % (Global.device, res))
+        if res == 4:
+            dprint("Oh oh -- 'clear' failed! trying one more time ...")
+        ts = time.time()
+        res = run_cmd(['sgdisk', '--clear', Global.device])
+        te = time.time()
+        if res != 0:
+            return (res, '%s: could not zero out label after two tries: %d' % \
+                    (Global.device, res))
+        Global.sgdisk_time += (te - ts)
+    ts = time.time()
     res = run_cmd(['dd', 'if=/dev/zero', 'of=%s' % Global.device, 'bs=256k', 'count=20', 'oflag=direct'])
+    te = time.time()
     if res != 0:
         return (res, '%s: could not zero out filesystem: %d' % (Global.device, res))
+    Global.dd_time += (te - ts)
     return (0, 'Success')
     
 def run_parted():
@@ -339,7 +364,7 @@ def run_parted():
     """
     (res, reason) = wipe_disc()
     if res != 0:
-        return (res, resason)
+        return (res, reason)
     # ensure our partition file is not there, to be safe
     if not wait_for_path(Global.partition, present=False, amt=30):
         return (1, '%s: Partition already exists?' % Global.partition)
@@ -359,25 +384,39 @@ def run_parted():
 
 def run_mkfs():
     vprint('Running "mkfs" to to create filesystem')
+    ts = time.time()
     res = run_cmd(Global.MKFSCMD + [ Global.partition ] )
+    te = time.time()
     if res != 0:
         return (res, '%s: mkfs failed (%d)' % (Global.partition, res))
+    Global.mkfs_time += (te - ts)
     return (0, 'Success')
 
 def run_bonnie():
     # make a temp dir and mount the device there
     with tempfile.TemporaryDirectory() as tmp_dir:
-        vprint('Mounting the filesystem')
+        vprint('Running "mount" to mount the filesystem')
         res = run_cmd(['mount'] + Global.MOUNTOPTIONS + [Global.partition, tmp_dir])
         if res != 0:
             return (res, '%s: mount failed (%d)' % (Global.partition, res))
         # run bonnie++ on the new directory
         vprint('Running "bonnie++" on the filesystem')
+        ts = time.time()
         res = run_cmd(['bonnie++'] + Global.BONNIEPARAMS + ['-d', tmp_dir])
+        te = time.time()
         if res != 0:
             return (res, '%s: umount failed (%d)' % (tmp_dir, res))
+        Global.bonnie_time += (te - ts)
         # unmount the device and remove the temp dir
+        vprint('Running "umount" to unmount the filesystem')
         res = run_cmd(['umount', tmp_dir])
         if res != 0:
             return (res, '%s: umount failed (%d)' % (tmp_dir, res))
     return (0, 'Success')
+
+def sleep_some(s):
+    # sleep s seconds
+    ts = time.time()
+    time.sleep(s)
+    te = time.time()
+    Global.sleep_time += (te - ts)