ZTS: Fix create-o_ashift test case

[loli10K]

Description

The function that fills the uberblock ring buffer on every device label has been reworked to avoid occasional failures caused by a race condition that prevents 'zpool sync' from writing some uberblock
sequentially: this happens when the pool sync ioctl dispatch code calls txg_wait_synced() while we're already waiting for a TXG to sync.

Root Cause Analysis

On a local builder i added some zfs_dbgmsg() calls and modified zfs_ioc_pool_sync() to call txg_wait_synced(spa_get_dsl(spa), spa_last_synced_txg(spa) + 1) just to help troubleshooting.

The resulting dbgmsg log shows why we skip writing uberblock [7]: we call txg_wait_synced() (after having dirtied spa->spa_root_vdev) while someone is already waiting for txg=7 to sync: since spa_last_synced_txg=5 we will only be writing uberblock [6] in this zfs_ioc_pool_sync() cycle, and because the test script was only going to zpool sync -f $TESTPOOL 128 times we won't have another chance to write uberblock [7].

1513516280   txg.c:657:txg_wait_synced(): txg=7 quiesce_txg=5 sync_txg=7
1513516280   txg.c:661:txg_wait_synced(): broadcasting sync more tx_synced=4 waiting=7 dp=ffff8800db1e6000
1513516280   vdev_label.c:1250:vdev_uberblock_sync():  [5] -> 
1513516280   vdev_label.c:200:vdev_label_write():  -> 0
1513516280   vdev_label.c:210:vdev_label_write():  <- 0
1513516280   vdev_label.c:200:vdev_label_write():  -> 1
1513516280   vdev_label.c:210:vdev_label_write():  <- 1
1513516280   vdev_label.c:200:vdev_label_write():  -> 2
1513516280   vdev_label.c:210:vdev_label_write():  <- 2
1513516280   vdev_label.c:200:vdev_label_write():  -> 3
1513516280   vdev_label.c:210:vdev_label_write():  <- 3
1513516280   zfs_ioctl.c:6025:zfs_ioc_pool_sync():  -> (spa_last_synced_txg = 5) 
1513516280   txg.c:661:txg_wait_synced(): broadcasting sync more tx_synced=5 waiting=7 dp=ffff8800db1e6000
1513516280   txg.c:657:txg_wait_synced(): txg=6 quiesce_txg=7 sync_txg=7
1513516280   txg.c:661:txg_wait_synced(): broadcasting sync more tx_synced=5 waiting=7 dp=ffff8800db1e6000
1513516280   vdev_label.c:200:vdev_label_write():  -> 0
1513516280   vdev_label.c:210:vdev_label_write():  <- 0
1513516280   vdev_label.c:200:vdev_label_write():  -> 2
1513516280   vdev_label.c:210:vdev_label_write():  <- 2
1513516280   vdev_label.c:1250:vdev_uberblock_sync():  [6] -> 
1513516280   vdev_label.c:200:vdev_label_write():  -> 0
1513516280   vdev_label.c:210:vdev_label_write():  <- 0
1513516280   vdev_label.c:200:vdev_label_write():  -> 1
1513516280   vdev_label.c:210:vdev_label_write():  <- 1
1513516280   vdev_label.c:200:vdev_label_write():  -> 2
1513516280   vdev_label.c:210:vdev_label_write():  <- 2
1513516280   vdev_label.c:200:vdev_label_write():  -> 3
1513516280   vdev_label.c:210:vdev_label_write():  <- 3
1513516280   vdev_label.c:1256:vdev_uberblock_sync():  [6] <- 
1513516280   vdev_label.c:200:vdev_label_write():  -> 1
1513516280   vdev_label.c:210:vdev_label_write():  <- 1
1513516280   vdev_label.c:200:vdev_label_write():  -> 3
1513516280   vdev_label.c:210:vdev_label_write():  <- 3
1513516280   txg.c:661:txg_wait_synced(): broadcasting sync more tx_synced=6 waiting=7 dp=ffff8800db1e6000
1513516280   txg.c:661:txg_wait_synced(): broadcasting sync more tx_synced=6 waiting=7 dp=ffff8800db1e6000
1513516280   zfs_ioctl.c:6029:zfs_ioc_pool_sync():  <- (spa_last_synced_txg = 7)
1513516280   zfs_ioctl.c:6025:zfs_ioc_pool_sync():  -> (spa_last_synced_txg = 7) 
1513516280   txg.c:657:txg_wait_synced(): txg=8 quiesce_txg=8 sync_txg=8
1513516280   txg.c:661:txg_wait_synced(): broadcasting sync more tx_synced=7 waiting=8 dp=ffff8800db1e6000
1513516280   vdev_label.c:200:vdev_label_write():  -> 0
1513516280   vdev_label.c:210:vdev_label_write():  <- 0
1513516280   vdev_label.c:200:vdev_label_write():  -> 2
1513516280   vdev_label.c:210:vdev_label_write():  <- 2
1513516280   vdev_label.c:1250:vdev_uberblock_sync():  [8] -> 
1513516280   vdev_label.c:200:vdev_label_write():  -> 0
1513516280   vdev_label.c:210:vdev_label_write():  <- 0
1513516280   vdev_label.c:200:vdev_label_write():  -> 1
1513516280   vdev_label.c:210:vdev_label_write():  <- 1
1513516280   vdev_label.c:200:vdev_label_write():  -> 2
1513516280   vdev_label.c:210:vdev_label_write():  <- 2
1513516280   vdev_label.c:200:vdev_label_write():  -> 3
1513516280   vdev_label.c:210:vdev_label_write():  <- 3
1513516280   vdev_label.c:1256:vdev_uberblock_sync():  [8] <- 
1513516280   vdev_label.c:200:vdev_label_write():  -> 1
1513516280   vdev_label.c:210:vdev_label_write():  <- 1
1513516280   vdev_label.c:200:vdev_label_write():  -> 3
1513516280   vdev_label.c:210:vdev_label_write():  <- 3
1513516280   zfs_ioctl.c:6029:zfs_ioc_pool_sync():  <- (spa_last_synced_txg = 8)

Motivation and Context

Fix #6924

How Has This Been Tested?

Types of changes

• Bug fix (non-breaking change which fixes an issue)
• New feature (non-breaking change which adds functionality)
• Performance enhancement (non-breaking change which improves efficiency)
• Code cleanup (non-breaking change which makes code smaller or more readable)
• Breaking change (fix or feature that would cause existing functionality to change)
• Documentation (a change to man pages or other documentation)

Checklist:

• My code follows the ZFS on Linux code style requirements.
• I have updated the documentation accordingly.
• I have read the CONTRIBUTING document.
• I have added tests to cover my changes.
• All new and existing tests passed.
• All commit messages are properly formatted and contain Signed-off-by.
• Change has been approved by a ZFS on Linux member.

[behlendorf]

The updated approach looks reasonable. While your here I think it'd be worth while to also reduce some of this log noise.

23:12:54.10 SUCCESS: sync_pool testpool true
23:12:54.22 SUCCESS: zpool sync -f testpool

[loli10K]

@behlendorf right, log_must sync_pool is useless since sync_pool() already uses log_must() internally.

[codecov]

Codecov Report

Merging #6977 into master will decrease coverage by 0.1%.
The diff coverage is 33.33%.

@@            Coverage Diff             @@
##           master    #6977      +/-   ##
==========================================
- Coverage   75.27%   75.16%   -0.11%     
==========================================
  Files         296      296              
  Lines       95454    95454              
==========================================
- Hits        71851    71748     -103     
- Misses      23603    23706     +103

Flag	Coverage Δ
#kernel	74.29% <ø> (-0.19%)	⬇️
#user	67.46% <33.33%> (-0.13%)	⬇️

---

Continue to review full report at Codecov.

Legend - Click here to learn more
Δ = absolute <relative> (impact), ø = not affected, ? = missing data
Powered by Codecov. Last update bbffb59...44bd278. Read the comment docs.

[behlendorf]

Looks good and seems to hold up well. I'll go ahead and merge it, thanks!