device-mapper-test-suite icon indicating copy to clipboard operation
device-mapper-test-suite copied to clipboard

Published 20 hours ago • verified publisher icon jthornber

ProcessControl::ExitError: command failed

Open simonxuhao opened this issue 9 years ago • 8 comments

When I run tests, I get a lot of "ProcessControl::ExitError: command failed", e.g.

[root@mybox device-mapper-test-suite]# dmtest run --suite cache --profile mix Loaded suite cache Started BackgroundWritebackTests clean_data_never_gets_written_back...FAIL dirty_data_always_gets_written_back...FAIL BurstyWriteTests git_extract_cache_16...FAIL git_extract_cache_256...FAIL git_extract_cache_512...FAIL git_extract_cache_64...FAIL git_extract_linear...formatting ... getting repo ... FAIL smallfile_cache...FAIL smallfile_linear...FAIL CacheTests bonnie_cache...FAIL bonnie_linear...PASS cache_grow...FAIL cache_sizing_effect_mq...FAIL cleaner_policy...FAIL construct_cache...FAIL dd_cache...FAIL dd_linear...PASS dt_cache...FAIL dt_linear...PASS fio_cache...FAIL fio_database_funtime...FAIL fio_linear...FAIL fio_sub_volume...FAIL format_cache...FAIL format_linear...Elapsed 3.026720887: formatting Elapsed 2.532178736: mount/umount/fsck PASS git_extract_cache...FAIL git_extract_cache_quick...FAIL git_extract_cache_quick_across_migration_threshold...FAIL git_extract_cache_quick_mq...FAIL git_extract_linear...formatting ... getting repo ... FAIL git_extract_linear_quick...formatting ... getting repo ... FAIL git_extract_only_cache_quick_mq...formatting ... getting repo ... FAIL message...FAIL metadata_persists...FAIL origin_grow...FAIL origin_shrink...FAIL status...FAIL suspend_resume...FAIL table...FAIL table_reload...FAIL table_reload_changed_policy...FAIL unknown_policy_fails...PASS writethrough...FAIL HintWidthTests hint_size_is_dumped_correctly...FAIL various_hint_widths_can_be_reloaded...FAIL IOUseTests no_io_when_idle...FAIL InitialWarmingTests tunables_0...formatting ... getting repo ... FAIL tunables_10...formatting ... getting repo ... FAIL InvalidateCBlocksTests badly_formed_range...PASS invalidating_all_cblocks_in_a_full_cache...FAIL invalidating_all_cblocks_in_an_empty_cache...FAIL invalidating_multiple_args...FAIL must_be_in_passthrough_mode...FAIL out_of_bounds_range...PASS InvalidationTests external_storage_snap_and_rollback...PASS invalidation_works_on_rollback...FAIL with_io_mode...FAIL LargeConfigTests bug_1080894...FAIL dt_in_chunks...FAIL large_stack...FAIL MetadataScalingTests metadata_use_kernel...FAIL metadata_use_restored...FAIL MetadataVersionTests kernel_detects_bad_metadata_version...PASS MultiBlockPromotionTests promotions_to_a_cold_cache_occur_reads...FAIL promotions_to_a_cold_cache_occur_writes...FAIL promotions_to_a_discarded_device_occur...FAIL promotions_to_a_warm_cache_occur_reads...FAIL promotions_to_a_warm_cache_occur_writes...FAIL NoCleanShutdownTests no_resize_retains_mappings_all_clean...FAIL PassthroughTests passthrough_demotes_writes...FAIL passthrough_does_not_demote_reads...FAIL passthrough_fails_with_dirty_blocks...PASS passthrough_never_promotes...FAIL ResidencyTests residency_is_persisted...FAIL ResizeTests metadata_can_grow...FAIL metadata_can_shrink...FAIL no_resize_retains_mappings_all_clean...FAIL no_resize_retains_mappings_all_dirty...FAIL resize_origin_with_reload...FAIL resize_origin_with_teardown...FAIL SingleBlockPromotionTests promotions_to_a_cold_cache_occur_reads...FAIL promotions_to_a_cold_cache_occur_writes...FAIL promotions_to_a_discarded_device_occur...FAIL promotions_to_a_warm_cache_occur_reads...FAIL promotions_to_a_warm_cache_occur_writes...FAIL SmallConfigTests small_stack...FAIL ToolsTests can_dump_kernel_metadata...FAIL can_restore_from_xml...FAIL formatting_in_kernel_works...FAIL VDBenchTests vdbench...FAIL

Finished in 134.922440428 seconds.

  1. Error: test_clean_data_never_gets_written_back(BackgroundWritebackTests): ProcessControl::ExitError: command failed: dmsetup load test-dev-122723 /tmp/dm-table20150322-7798-1yv7p6v /root/device-mapper-test-suite/lib/dmtest/process.rb:96:in wait' /root/device-mapper-test-suite/lib/dmtest/process.rb:111:inreally_run' /root/device-mapper-test-suite/lib/dmtest/process.rb:116:in run_' /root/device-mapper-test-suite/lib/dmtest/process.rb:138:inrun' /root/device-mapper-test-suite/lib/dmtest/device-mapper/interface.rb:16:in block in load' /root/device-mapper-test-suite/lib/dmtest/utils.rb:82:inwith_temp_file' /root/device-mapper-test-suite/lib/dmtest/device-mapper/interface.rb:12:in load' /root/device-mapper-test-suite/lib/dmtest/device-mapper/dev.rb:19:inload' /root/device-mapper-test-suite/lib/dmtest/device-mapper/lexical_operators.rb:53:in block in create' /root/device-mapper-test-suite/lib/dmtest/prelude.rb:39:inprotect_' /root/device-mapper-test-suite/lib/dmtest/device-mapper/lexical_operators.rb:47:in create' /root/device-mapper-test-suite/lib/dmtest/device-mapper/lexical_operators.rb:10:inwith_dev' /root/device-mapper-test-suite/lib/dmtest/cache_stack.rb:80:in activate_top_level' /root/device-mapper-test-suite/lib/dmtest/tests/cache/background_writeback_tests.rb:45:inblock (2 levels) in test_clean_data_never_gets_written_back' /root/device-mapper-test-suite/lib/dmtest/blktrace.rb:95:in call' /root/device-mapper-test-suite/lib/dmtest/blktrace.rb:95:inblktrace' /root/device-mapper-test-suite/lib/dmtest/tests/cache/background_writeback_tests.rb:44:in block in test_clean_data_never_gets_written_back' /root/device-mapper-test-suite/lib/dmtest/ensure_elapsed.rb:13:incall' /root/device-mapper-test-suite/lib/dmtest/ensure_elapsed.rb:13:in ensure_elapsed_time' /root/device-mapper-test-suite/lib/dmtest/cache_stack.rb:75:inblock in activate_support_devs' /root/device-mapper-test-suite/lib/dmtest/device-mapper/lexical_operators.rb:37:in call' /root/device-mapper-test-suite/lib/dmtest/device-mapper/lexical_operators.rb:37:inblock in with_devs' /root/device-mapper-test-suite/lib/dmtest/prelude.rb:6:in bracket' /root/device-mapper-test-suite/lib/dmtest/device-mapper/lexical_operators.rb:32:inwith_devs' /root/device-mapper-test-suite/lib/dmtest/cache_stack.rb:67:in activate_support_devs' /root/device-mapper-test-suite/lib/dmtest/tests/cache/background_writeback_tests.rb:41:intest_clean_data_never_gets_written_back'

....

[root@mybox device-mapper-test-suite]# dmtest run --suite bcache --profile mix Loaded suite bcache Started BcacheTests fio_database_funtime...FAIL fio_sub_volume...FAIL git_extract_quick...FAIL

Finished in 10.502897628 seconds.

  1. Error: test_fio_database_funtime(BcacheTests): ProcessControl::ExitError: command failed: make-bcache --cache_replacement_policy=lru -b 128k --writeback --discard -B /dev/mapper/test-dev-480498 -C /dev/mapper/test-dev-59724 /root/device-mapper-test-suite/lib/dmtest/process.rb:96:in wait' /root/device-mapper-test-suite/lib/dmtest/process.rb:111:inreally_run' /root/device-mapper-test-suite/lib/dmtest/process.rb:116:in run_' /root/device-mapper-test-suite/lib/dmtest/process.rb:138:inrun' /root/device-mapper-test-suite/lib/dmtest/tests/cache/bcache_tests.rb:48:in block in activate' /root/device-mapper-test-suite/lib/dmtest/device-mapper/lexical_operators.rb:37:incall' /root/device-mapper-test-suite/lib/dmtest/device-mapper/lexical_operators.rb:37:in block in with_devs' /root/device-mapper-test-suite/lib/dmtest/prelude.rb:6:inbracket' /root/device-mapper-test-suite/lib/dmtest/device-mapper/lexical_operators.rb:32:in with_devs' /root/device-mapper-test-suite/lib/dmtest/tests/cache/bcache_tests.rb:45:inactivate' /root/device-mapper-test-suite/lib/dmtest/tests/cache/bcache_tests.rb:118:in `test_fio_database_funtime'

  2. Error: test_fio_sub_volume(BcacheTests): ProcessControl::ExitError: command failed: make-bcache --cache_replacement_policy=lru -b 512k --writeback --discard -B /dev/mapper/test-dev-621395 -C /dev/mapper/test-dev-371818 /root/device-mapper-test-suite/lib/dmtest/process.rb:96:in wait' /root/device-mapper-test-suite/lib/dmtest/process.rb:111:inreally_run' /root/device-mapper-test-suite/lib/dmtest/process.rb:116:in run_' /root/device-mapper-test-suite/lib/dmtest/process.rb:138:inrun' /root/device-mapper-test-suite/lib/dmtest/tests/cache/bcache_tests.rb:48:in block in activate' /root/device-mapper-test-suite/lib/dmtest/device-mapper/lexical_operators.rb:37:incall' /root/device-mapper-test-suite/lib/dmtest/device-mapper/lexical_operators.rb:37:in block in with_devs' /root/device-mapper-test-suite/lib/dmtest/prelude.rb:6:inbracket' /root/device-mapper-test-suite/lib/dmtest/device-mapper/lexical_operators.rb:32:in with_devs' /root/device-mapper-test-suite/lib/dmtest/tests/cache/bcache_tests.rb:45:inactivate' /root/device-mapper-test-suite/lib/dmtest/tests/cache/bcache_tests.rb:106:in `test_fio_sub_volume'

  3. Error: test_git_extract_quick(BcacheTests): ProcessControl::ExitError: command failed: make-bcache --cache_replacement_policy=lru -b 512k --writeback --discard -B /dev/mapper/test-dev-127828 -C /dev/mapper/test-dev-494994 /root/device-mapper-test-suite/lib/dmtest/process.rb:96:in wait' /root/device-mapper-test-suite/lib/dmtest/process.rb:111:inreally_run' /root/device-mapper-test-suite/lib/dmtest/process.rb:116:in run_' /root/device-mapper-test-suite/lib/dmtest/process.rb:138:inrun' /root/device-mapper-test-suite/lib/dmtest/tests/cache/bcache_tests.rb:48:in block in activate' /root/device-mapper-test-suite/lib/dmtest/device-mapper/lexical_operators.rb:37:incall' /root/device-mapper-test-suite/lib/dmtest/device-mapper/lexical_operators.rb:37:in block in with_devs' /root/device-mapper-test-suite/lib/dmtest/prelude.rb:6:inbracket' /root/device-mapper-test-suite/lib/dmtest/device-mapper/lexical_operators.rb:32:in with_devs' /root/device-mapper-test-suite/lib/dmtest/tests/cache/bcache_tests.rb:45:inactivate' /root/device-mapper-test-suite/lib/dmtest/tests/cache/bcache_tests.rb:94:in `test_git_extract_quick'

3 tests, 0 assertions, 0 failures, 3 errors

When the test runs, I can't find any /dev/mapper/test-dev* in the system. Is the system missing any packages that are required by the test suite?

simonxuhao avatar Mar 22 '15 04:03 simonxuhao

dmsetup is failing to load the table. The likely reason is you haven't built one of the targets used by that table.

There are a few tests that use some debug targets that are only present in my thin-dev tree. But this is occuring so often I think you may be missing the dm-cache target itself.

Check the log files in ~/.dmtest/log/

jthornber avatar Mar 22 '15 07:03 jthornber

How should I create the dm-cache target? How should I create the debug targets?

simonxuhao avatar Mar 23 '15 03:03 simonxuhao

Double check the logs first please.

On Mon, 23 Mar 2015 at 03:20 Simon Xu [email protected] wrote:

How should I create the dm-cache target? How should I create the debug targets?

— Reply to this email directly or view it on GitHub https://github.com/jthornber/device-mapper-test-suite/issues/40#issuecomment-84775334 .

jthornber avatar Mar 23 '15 07:03 jthornber

There are so many failures. Please first have a look at FakeDiscardTests_granularity_equals_max_discard.log:

D, [2015-03-23T22:29:11.590051 #5351] DEBUG -- : executing: 'blockdev --getsz /dev/sdc' D, [2015-03-23T22:29:11.592101 #5351] DEBUG -- : stdout: 1172123568 D, [2015-03-23T22:29:11.592247 #5351] DEBUG -- : executing: 'dmsetup create test-dev-834780 --notable' D, [2015-03-23T22:29:11.595367 #5351] DEBUG -- : writing table: <<table:0 1172123568 fake-discard /dev/sdc 0 64 64 0>> D, [2015-03-23T22:29:11.595442 #5351] DEBUG -- : executing: 'dmsetup load test-dev-834780 /tmp/dm-table20150323-5351-1rvuibx' D, [2015-03-23T22:29:11.599018 #5351] DEBUG -- : stderr: device-mapper: reload ioctl on test-dev-834780 failed: Invalid argument Command failed D, [2015-03-23T22:29:11.599180 #5351] DEBUG -- : command failed with 'pid 5441 exit 1': dmsetup load test-dev-834780 /tmp/dm-table20150323-5351-1rvuibx D, [2015-03-23T22:29:11.599334 #5351] DEBUG -- : executing: 'dmsetup remove test-dev-834780' E, [2015-03-23T22:29:11.616433 #5351] ERROR -- : Error: test_granularity_equals_max_discard(FakeDiscardTests): ProcessControl::ExitError: command failed: dmsetup load test-dev-834780 /tmp/dm-table20150323-5351-1rvuibx /root/device-mapper-test-suite/lib/dmtest/process.rb:96:in wait' /root/device-mapper-test-suite/lib/dmtest/process.rb:111:inreally_run' /root/device-mapper-test-suite/lib/dmtest/process.rb:116:in run_' /root/device-mapper-test-suite/lib/dmtest/process.rb:138:inrun' /root/device-mapper-test-suite/lib/dmtest/device-mapper/interface.rb:16:in block in load' /root/device-mapper-test-suite/lib/dmtest/utils.rb:82:inwith_temp_file' /root/device-mapper-test-suite/lib/dmtest/device-mapper/interface.rb:12:in load' /root/device-mapper-test-suite/lib/dmtest/device-mapper/dev.rb:19:inload' /root/device-mapper-test-suite/lib/dmtest/device-mapper/lexical_operators.rb:53:in block in create' /root/device-mapper-test-suite/lib/dmtest/prelude.rb:39:inprotect_' /root/device-mapper-test-suite/lib/dmtest/device-mapper/lexical_operators.rb:47:in create' /root/device-mapper-test-suite/lib/dmtest/device-mapper/lexical_operators.rb:10:inwith_dev' /root/device-mapper-test-suite/lib/dmtest/thinp-mixin.rb:147:in with_fake_discard' /root/device-mapper-test-suite/lib/dmtest/tests/fake-discard/fake-discard-tests.rb:63:inblock in test_granularity_equals_max_discard' /root/device-mapper-test-suite/lib/dmtest/tests/fake-discard/fake-discard-tests.rb:62:in each' /root/device-mapper-test-suite/lib/dmtest/tests/fake-discard/fake-discard-tests.rb:62:intest_granularity_equals_max_discard' I, [2015-03-23T22:29:11.616624 #5351] INFO -- : Peak bufio allocation was 0

I checked, there is no test-dev-834780 under /dev/mapper.

Any idea of the failure?

What dm kernel modules needs to be loaded when running the test suite?

Here's the dm modules loaded in my system:

$ lsmod | grep dm_ dm_verity 17426 0 dm_zero 12529 0 dm_thin_pool 56142 0 dm_era 26954 0 dm_cache_cleaner 13084 0 dm_cache 47432 1 dm_cache_cleaner dm_persistent_data 61869 3 dm_era,dm_cache,dm_thin_pool dm_bio_prison 15457 2 dm_cache,dm_thin_pool dm_bufio 27932 2 dm_persistent_data,dm_verity libcrc32c 12644 2 xfs,dm_persistent_data dm_mirror 22135 0 dm_region_hash 20862 1 dm_mirror dm_log 18411 2 dm_region_hash,dm_mirror dm_mod 103459 18 dm_zero,dm_era,dm_log,dm_persistent_data,dm_mirror,dm_cache,dm_bufio,dm_verity,dm_thin_pool

simonxuhao avatar Mar 23 '15 14:03 simonxuhao

The FakeDiscard tests use this target from my thin-dev tree:

https://github.com/jthornber/linux-2.6/blob/thin-dev/drivers/md/dm-fake-discard.c

Perhaps we should rewind a bit. What are you trying to achieve?

On Mon, 23 Mar 2015 at 14:36 Simon Xu [email protected] wrote:

There are so many failures. Please first have a look at FakeDiscardTests_granularity_equals_max_discard.log:

D, [2015-03-23T22:29:11.590051 #5351] DEBUG -- : executing: 'blockdev --getsz /dev/sdc' D, [2015-03-23T22:29:11.592101 #5351] DEBUG -- : stdout: 1172123568 D, [2015-03-23T22:29:11.592247 #5351] DEBUG -- : executing: 'dmsetup create test-dev-834780 --notable' D, [2015-03-23T22:29:11.595367 #5351] DEBUG -- : writing table: <> D, [2015-03-23T22:29:11.595442 #5351] DEBUG -- : executing: 'dmsetup load test-dev-834780 /tmp/dm-table20150323-5351-1rvuibx' D, [2015-03-23T22:29:11.599018 #5351] DEBUG -- : stderr: device-mapper: reload ioctl on test-dev-834780 failed: Invalid argument Command failed D, [2015-03-23T22:29:11.599180 #5351] DEBUG -- : command failed with 'pid 5441 exit 1': dmsetup load test-dev-834780 /tmp/dm-table20150323-5351-1rvuibx D, [2015-03-23T22:29:11.599334 #5351] DEBUG -- : executing: 'dmsetup remove test-dev-834780' E, [2015-03-23T22:29:11.616433 #5351] ERROR -- : Error: test_granularity_equals_max_discard(FakeDiscardTests): ProcessControl::ExitError: command failed: dmsetup load test-dev-834780 /tmp/dm-table20150323-5351-1rvuibx

/root/device-mapper-test-suite/lib/dmtest/process.rb:96:in wait' /root/device-mapper-test-suite/lib/dmtest/process.rb:111:inreally_run' /root/device-mapper-test-suite/lib/dmtest/process.rb:116:in run_' /root/device-mapper-test-suite/lib/dmtest/process.rb:138:inrun' /root/device-mapper-test-suite/lib/dmtest/device-mapper/interface.rb:16:in block in load' /root/device-mapper-test-suite/lib/dmtest/utils.rb:82:inwith_temp_file' /root/device-mapper-test-suite/lib/dmtest/device-mapper/interface.rb:12:in load' /root/device-mapper-test-suite/lib/dmtest/device-mapper/dev.rb:19:inload' /root/device-mapper-test-suite/lib/dmtest/device-mapper/lexical_operators.rb:53:in block in create' /root/device-mapper-test-suite/lib/dmtest/prelude.rb:39:inprotect_' /root/device-mapper-test-suite/lib/dmtest/device-mapper/lexical_operators.rb:47:in create'

/root/device-mapper-test-suite/lib/dmtest/device-mapper/lexical_operators.rb:10:in with_dev'

/root/device-mapper-test-suite/lib/dmtest/thinp-mixin.rb:147:in with_fake_discard'

/root/device-mapper-test-suite/lib/dmtest/tests/fake-discard/fake-discard-tests.rb:63:inblock in test_granularity_equals_max_discard' /root/device-mapper-test-suite/lib/dmtest/tests/fake-discard/fake-discard-tests.rb:62:in each'

/root/device-mapper-test-suite/lib/dmtest/tests/fake-discard/fake-discard-tests.rb:62:in test_granularity_equals_max_discard' I, [2015-03-23T22:29:11.616624 #5351] INFO -- : Peak bufio allocation was 0

I checked, there is no test-dev-834780 under /dev/mapper.

Any idea of the failure?

What dm kernel modules needs to be loaded when running the test suite?

Here's the dm modules loaded in my system: lsmod | grep dm_

dm_verity 17426 0 dm_zero 12529 0 dm_thin_pool 56142 0 dm_era 26954 0 dm_cache_cleaner 13084 0 dm_cache 47432 1 dm_cache_cleaner dm_persistent_data 61869 3 dm_era,dm_cache,dm_thin_pool dm_bio_prison 15457 2 dm_cache,dm_thin_pool dm_bufio 27932 2 dm_persistent_data,dm_verity libcrc32c 12644 2 xfs,dm_persistent_data dm_mirror 22135 0 dm_region_hash 20862 1 dm_mirror dm_log 18411 2 dm_region_hash,dm_mirror dm_mod 103459 18 dm_zero,dm_era,dm_log,dm_persistent_data,dm_mirror,dm_cache,dm_bufio,dm_verity,dm_thin_pool

— Reply to this email directly or view it on GitHub https://github.com/jthornber/device-mapper-test-suite/issues/40#issuecomment-85027759 .

jthornber avatar Mar 23 '15 14:03 jthornber

My primary goal is to verify that the dm-cache and dm-era modules of my kernel work well. A secondary goal is to use device-mapper-test-suite as a test tool for the device mapper functionality of my kernel.

simonxuhao avatar Mar 23 '15 14:03 simonxuhao

What are you planning to use dm-era for? (I'm just interested since i don't think people have picked up how helpful this is yet).

On Mon, 23 Mar 2015 at 14:46 Simon Xu [email protected] wrote:

My primary goal is to verify that the dm-cache and dm-era modules of my kernel work well. A secondary goal is to use device-mapper-test-suite as a test tool for the device mapper functionality of my kernel.

— Reply to this email directly or view it on GitHub https://github.com/jthornber/device-mapper-test-suite/issues/40#issuecomment-85031332 .

jthornber avatar Mar 23 '15 14:03 jthornber

I don't have any plan for using dm-era, I just need to sanity test the newly-added kernel module of the kernel of a Linux distribution.

simonxuhao avatar Mar 23 '15 14:03 simonxuhao