|
| 1 | +""" |
| 2 | +Recovery tests for dm-vdo. |
| 3 | +
|
| 4 | +These tests trigger the recovery path by replacing the storage device |
| 5 | +under dm-vdo with a dm-error target mid-operation, then verifying that |
| 6 | +dm-vdo can recover to a consistent state. |
| 7 | +""" |
| 8 | + |
| 9 | +from dmtest.assertions import assert_equal, assert_matches |
| 10 | +from dmtest.device_mapper import dev as dmdev |
| 11 | +from dmtest.device_mapper import table, targets |
| 12 | +from dmtest.vdo.utils import standard_vdo, wait_for_index, fsync |
| 13 | +from dmtest.vdo.utils import BLOCK_SIZE, SECTOR_SIZE |
| 14 | +from dmtest.vdo.vdo_stack import VDOStack |
| 15 | +import dmtest.vdo.stats as stats |
| 16 | +import dmtest.vdo.status as status |
| 17 | +from dmtest.gendatablocks import make_block_range |
| 18 | +#import dmtest.process as process |
| 19 | +import dmtest.utils as utils |
| 20 | +import logging as log |
| 21 | +import re |
| 22 | +import threading |
| 23 | +import time |
| 24 | + |
| 25 | +def write_recovery_data(vdo, tag, block_size=BLOCK_SIZE): |
| 26 | + """Write some data to be interrupted by power loss.""" |
| 27 | + log.info("Writing up to 30000 blocks (should be interrupted)") |
| 28 | + blocks = make_block_range( |
| 29 | + path=vdo.path, |
| 30 | + block_size=BLOCK_SIZE, |
| 31 | + block_count=30000, |
| 32 | + offset=30000 |
| 33 | + ) |
| 34 | + # Try to write this data (it should fail partway) |
| 35 | + try: |
| 36 | + blocks.write(tag=tag, dedupe=0.1, compress=0.55, fsync=True) |
| 37 | + log.info("Finished writing 30000 blocks - this shouldn't happen") |
| 38 | + except: |
| 39 | + pass |
| 40 | + |
| 41 | + |
| 42 | +def fail_vdo_storage(vdo, linear, block_size=BLOCK_SIZE): |
| 43 | + """ |
| 44 | + Force a recovery by replacing the underlying storage with an error target. |
| 45 | + """ |
| 46 | + # Get stats before failure |
| 47 | + stats_before = stats.vdo_stats(vdo) |
| 48 | + log.info(f"Stats before failure - data blocks: {stats_before['dataBlocksUsed']}, " |
| 49 | + f"logical blocks: {stats_before['logicalBlocksUsed']}") |
| 50 | + |
| 51 | + recovery_start_time = time.time() |
| 52 | + async_write = threading.Thread(target=write_recovery_data, |
| 53 | + args=(vdo, "fail", block_size,)) |
| 54 | + async_write.start() |
| 55 | + linear_size = utils.dev_size(linear) |
| 56 | + time.sleep(0.5) |
| 57 | + |
| 58 | + log.info("Replacing storage with error target") |
| 59 | + with linear.pause(): |
| 60 | + error_table = table.Table(targets.ErrorTarget(linear_size)) |
| 61 | + linear.load(error_table) |
| 62 | + |
| 63 | + async_write.join() |
| 64 | + |
| 65 | + # Flush pending writes to trigger an error |
| 66 | + try: |
| 67 | + fsync(vdo) |
| 68 | + except: |
| 69 | + pass |
| 70 | + |
| 71 | + return recovery_start_time |
| 72 | + |
| 73 | +def verify_vdo_recovery(vdo, start_time: float): |
| 74 | + """Verify that VDO recovered successfully to a consistent state.""" |
| 75 | + # Wait for index to come online |
| 76 | + wait_for_index(vdo) |
| 77 | + |
| 78 | + # Check the logs to make sure recovery really happened |
| 79 | + # If one of these assertions fails, the rebuild likely didn't happen |
| 80 | + message = utils.get_dmesg_log(start_time) |
| 81 | + assert_matches(message, r'[Rr]ebuilding reference counts') |
| 82 | + assert_matches(message, r'[Rr]ebuild complete') |
| 83 | + |
| 84 | + match = re.search(r'[Rr]eplaying (\d+) recovery entries into block map', message) |
| 85 | + if match: |
| 86 | + recovery_entries = match.group(0) |
| 87 | + log.info(f"Replayed {recovery_entries} recovery entries") |
| 88 | + |
| 89 | + # vdo Status should be normal |
| 90 | + vdo_status = status.vdo_status(vdo) |
| 91 | + log.info(f"VDO status after recovery: {vdo_status}") |
| 92 | + |
| 93 | + assert_equal(vdo_status["mode"], "normal", |
| 94 | + "VDO should be in normal mode after recovery") |
| 95 | + assert_equal(vdo_status["index-state"], "online", |
| 96 | + "VDO index should be online after recovery") |
| 97 | + |
| 98 | + # Get stats to verify no catastrophic errors |
| 99 | + vdo_stats = stats.vdo_stats(vdo) |
| 100 | + log.info(f"VDO stats after recovery - data blocks: {vdo_stats['dataBlocksUsed']}, " |
| 101 | + f"logical blocks: {vdo_stats['logicalBlocksUsed']}") |
| 102 | + |
| 103 | +def t_single_recovery(fix): |
| 104 | + """ |
| 105 | + Test VDO recovery after a failure during write operations. |
| 106 | + """ |
| 107 | + cfg = fix.cfg |
| 108 | + data_dev = cfg["data_dev"] |
| 109 | + data_size = utils.dev_size(data_dev) |
| 110 | + |
| 111 | + # Create an intermediate dm-linear device so we can control the storage |
| 112 | + log.info(f"Creating dm-linear device on {data_dev} ({data_size} sectors)") |
| 113 | + linear_table = table.Table(targets.LinearTarget(data_size, data_dev, 0)) |
| 114 | + |
| 115 | + with dmdev.dev(linear_table) as linear: |
| 116 | + log.info(f"Created linear device: {linear.path}") |
| 117 | + |
| 118 | + # Create and format vdo on the linear device |
| 119 | + with VDOStack(linear, format=True).activate() as vdo: |
| 120 | + log.info(f"Activated vdo device: {vdo.path}") |
| 121 | + wait_for_index(vdo) |
| 122 | + |
| 123 | + initial_blocks = make_block_range( |
| 124 | + path=vdo.path, |
| 125 | + block_size=BLOCK_SIZE, |
| 126 | + block_count=2500 |
| 127 | + ) |
| 128 | + initial_blocks.write(tag="initial", dedupe=0.1, compress=0.55, fsync=True) |
| 129 | + initial_blocks.verify() |
| 130 | + log.info("Initial data written and verified") |
| 131 | + |
| 132 | + # Get stats before failure simulation |
| 133 | + stats_before = stats.vdo_stats(vdo) |
| 134 | + log.info(f"vdostats before - data blocks: {stats_before['dataBlocksUsed']}, " |
| 135 | + f"logical blocks: {stats_before['logicalBlocksUsed']}") |
| 136 | + |
| 137 | + start_time = fail_vdo_storage(vdo, linear) |
| 138 | + |
| 139 | + # Restore the linear device to point back to real storage |
| 140 | + log.info("Restoring linear device to real storage") |
| 141 | + with linear.pause(): |
| 142 | + linear.load(linear_table) |
| 143 | + |
| 144 | + # Force a recovery by recreating the vdo target without formatting |
| 145 | + with VDOStack(linear, format=False).activate() as vdo: |
| 146 | + log.info(f"vdo recovery complete: {vdo.path}") |
| 147 | + verify_vdo_recovery(vdo, start_time) |
| 148 | + |
| 149 | + log.info("Verifying initial data") |
| 150 | + initial_blocks.update_path(vdo.path) |
| 151 | + initial_blocks.verify() |
| 152 | + |
| 153 | + # Write new data to prove VDO is functional |
| 154 | + log.info("Writing new data post-recovery to verify functionality") |
| 155 | + post_blocks = make_block_range( |
| 156 | + path=vdo.path, |
| 157 | + block_size=BLOCK_SIZE, |
| 158 | + block_count=1000, |
| 159 | + offset=30000 |
| 160 | + ) |
| 161 | + post_blocks.write(tag="post", dedupe=0.1, compress=0.55, fsync=True) |
| 162 | + post_blocks.verify() |
| 163 | + |
| 164 | + stats_after = stats.vdo_stats(vdo) |
| 165 | + log.info(f"vdostats after - data blocks: {stats_after['dataBlocksUsed']}, " |
| 166 | + f"logical blocks: {stats_after['logicalBlocksUsed']}") |
| 167 | + |
| 168 | +def t_double_recovery(fix): |
| 169 | + """ |
| 170 | + Test two consecutive recoveries. |
| 171 | + """ |
| 172 | + cfg = fix.cfg |
| 173 | + data_dev = cfg["data_dev"] |
| 174 | + data_size = utils.dev_size(data_dev) |
| 175 | + |
| 176 | + # Create an intermediate dm-linear device so we can control the storage |
| 177 | + log.info(f"Creating dm-linear device on {data_dev} ({data_size} sectors)") |
| 178 | + linear_table = table.Table(targets.LinearTarget(data_size, data_dev, 0)) |
| 179 | + |
| 180 | + with dmdev.dev(linear_table) as linear: |
| 181 | + log.info(f"Created linear device: {linear.path}") |
| 182 | + |
| 183 | + # Create and format vdo on the linear device |
| 184 | + with VDOStack(linear, format=True).activate() as vdo: |
| 185 | + log.info(f"Activated vdo device: {vdo.path}") |
| 186 | + wait_for_index(vdo) |
| 187 | + |
| 188 | + initial_blocks = make_block_range( |
| 189 | + path=vdo.path, |
| 190 | + block_size=BLOCK_SIZE, |
| 191 | + block_count=5000 |
| 192 | + ) |
| 193 | + initial_blocks.write(tag="initial", dedupe=0.1, compress=0.55, fsync=True) |
| 194 | + initial_blocks.verify() |
| 195 | + log.info("Initial data written and verified") |
| 196 | + |
| 197 | + # Get stats before failure simulation |
| 198 | + stats_before = stats.vdo_stats(vdo) |
| 199 | + log.info(f"vdostats before - data blocks: {stats_before['dataBlocksUsed']}, " |
| 200 | + f"logical blocks: {stats_before['logicalBlocksUsed']}") |
| 201 | + |
| 202 | + start_time = fail_vdo_storage(vdo, linear) |
| 203 | + |
| 204 | + # Restore the linear device to point back to real storage |
| 205 | + log.info("Restoring linear device to real storage") |
| 206 | + with linear.pause(): |
| 207 | + linear.load(linear_table) |
| 208 | + |
| 209 | + # Force a recovery by recreating the vdo target without formatting |
| 210 | + with VDOStack(linear, format=False).activate() as vdo: |
| 211 | + log.info(f"vdo recovery complete: {vdo.path}") |
| 212 | + verify_vdo_recovery(vdo, start_time) |
| 213 | + |
| 214 | + log.info("Verifying initial data") |
| 215 | + initial_blocks.update_path(vdo.path) |
| 216 | + initial_blocks.verify() |
| 217 | + |
| 218 | + # Write new data to prove VDO is functional |
| 219 | + log.info("Writing post-recovery data") |
| 220 | + mid_blocks = make_block_range( |
| 221 | + path=vdo.path, |
| 222 | + block_size=BLOCK_SIZE, |
| 223 | + block_count=2000, |
| 224 | + offset=5000 |
| 225 | + ) |
| 226 | + mid_blocks.write(tag="mid", dedupe=0.1, compress=0.55, fsync=True) |
| 227 | + mid_blocks.verify() |
| 228 | + |
| 229 | + stats_between = stats.vdo_stats(vdo) |
| 230 | + log.info(f"vdostats between - data blocks: {stats_between['dataBlocksUsed']}, " |
| 231 | + f"logical blocks: {stats_between['logicalBlocksUsed']}") |
| 232 | + |
| 233 | + # Fail the VDO again |
| 234 | + start_time = fail_vdo_storage(vdo, linear) |
| 235 | + |
| 236 | + log.info("Restoring linear device to real storage again") |
| 237 | + with linear.pause(): |
| 238 | + linear.load(linear_table) |
| 239 | + |
| 240 | + # Force another recovery |
| 241 | + with VDOStack(linear, format=False).activate() as vdo: |
| 242 | + log.info(f"second vdo recovery complete: {vdo.path}") |
| 243 | + verify_vdo_recovery(vdo, start_time) |
| 244 | + |
| 245 | + log.info("Verifying existing data") |
| 246 | + initial_blocks.update_path(vdo.path) |
| 247 | + initial_blocks.verify() |
| 248 | + mid_blocks.update_path(vdo.path) |
| 249 | + mid_blocks.verify() |
| 250 | + |
| 251 | + log.info("Writing more new data post-recovery") |
| 252 | + post_blocks = make_block_range( |
| 253 | + path=vdo.path, |
| 254 | + block_size=BLOCK_SIZE, |
| 255 | + block_count=2000, |
| 256 | + offset=7000 |
| 257 | + ) |
| 258 | + post_blocks.write(tag="post", dedupe=0.1, compress=0.55, fsync=True) |
| 259 | + post_blocks.verify() |
| 260 | + |
| 261 | + stats_after = stats.vdo_stats(vdo) |
| 262 | + log.info(f"vdostats after - data blocks: {stats_after['dataBlocksUsed']}, " |
| 263 | + f"logical blocks: {stats_after['logicalBlocksUsed']}") |
| 264 | + |
| 265 | +def t_512_recovery(fix): |
| 266 | + """ |
| 267 | + Test VDO recovery after a failure during write operations. |
| 268 | + """ |
| 269 | + cfg = fix.cfg |
| 270 | + data_dev = cfg["data_dev"] |
| 271 | + data_size = utils.dev_size(data_dev) |
| 272 | + |
| 273 | + # Create an intermediate dm-linear device so we can control the storage |
| 274 | + log.info(f"Creating dm-linear device on {data_dev} ({data_size} sectors)") |
| 275 | + linear_table = table.Table(targets.LinearTarget(data_size, data_dev, 0)) |
| 276 | + |
| 277 | + with dmdev.dev(linear_table) as linear: |
| 278 | + log.info(f"Created linear device: {linear.path}") |
| 279 | + |
| 280 | + # Create and format vdo with a small block size |
| 281 | + with VDOStack(linear, block_size=512, format=True).activate() as vdo: |
| 282 | + log.info(f"Activated vdo device: {vdo.path}") |
| 283 | + wait_for_index(vdo) |
| 284 | + |
| 285 | + initial_blocks = make_block_range( |
| 286 | + path=vdo.path, |
| 287 | + block_size=SECTOR_SIZE, |
| 288 | + block_count=20000 |
| 289 | + ) |
| 290 | + initial_blocks.write(tag="initial", dedupe=0.1, compress=0.55, fsync=True) |
| 291 | + initial_blocks.verify() |
| 292 | + log.info("Initial data written and verified") |
| 293 | + |
| 294 | + # Get stats before failure simulation |
| 295 | + stats_before = stats.vdo_stats(vdo) |
| 296 | + log.info(f"vdostats before - data blocks: {stats_before['dataBlocksUsed']}, " |
| 297 | + f"logical blocks: {stats_before['logicalBlocksUsed']}") |
| 298 | + |
| 299 | + start_time = fail_vdo_storage(vdo, linear, block_size=SECTOR_SIZE) |
| 300 | + |
| 301 | + # Restore the linear device to point back to real storage |
| 302 | + log.info("Restoring linear device to real storage") |
| 303 | + with linear.pause(): |
| 304 | + linear.load(linear_table) |
| 305 | + |
| 306 | + # Force a recovery by recreating the vdo target without formatting |
| 307 | + with VDOStack(linear, format=False).activate() as vdo: |
| 308 | + log.info(f"vdo recovery complete: {vdo.path}") |
| 309 | + verify_vdo_recovery(vdo, start_time) |
| 310 | + |
| 311 | + log.info("Verifying initial data") |
| 312 | + initial_blocks.update_path(vdo.path) |
| 313 | + initial_blocks.verify() |
| 314 | + |
| 315 | + # Write new data to prove VDO is functional |
| 316 | + log.info("Writing new data post-recovery to verify functionality") |
| 317 | + post_blocks = make_block_range( |
| 318 | + path=vdo.path, |
| 319 | + block_size=SECTOR_SIZE, |
| 320 | + block_count=5000, |
| 321 | + offset=20000 |
| 322 | + ) |
| 323 | + post_blocks.write(tag="post", dedupe=0.1, compress=0.55, fsync=True) |
| 324 | + post_blocks.verify() |
| 325 | + |
| 326 | + stats_after = stats.vdo_stats(vdo) |
| 327 | + log.info(f"vdostats after - data blocks: {stats_after['dataBlocksUsed']}, " |
| 328 | + f"logical blocks: {stats_after['logicalBlocksUsed']}") |
| 329 | + |
| 330 | +def register(tests): |
| 331 | + """Register recovery tests.""" |
| 332 | + tests.register_batch( |
| 333 | + "/vdo/recovery/", |
| 334 | + [ |
| 335 | + ("quick_recovery", t_single_recovery), |
| 336 | + ("double_recovery", t_double_recovery), |
| 337 | + ("512_recovery", t_512_recovery), |
| 338 | + ], |
| 339 | + ) |
0 commit comments