From d741508330daeb56442af5988d5de0977d662d37 Mon Sep 17 00:00:00 2001 From: Emery Hemingway Date: Wed, 17 Aug 2016 11:21:28 +0200 Subject: [PATCH] test/vfs_stress: ugrade logging, reduce to single thread Issue #1987 --- repos/os/src/test/vfs_stress/main.cc | 297 ++++++++++++--------------- 1 file changed, 126 insertions(+), 171 deletions(-) diff --git a/repos/os/src/test/vfs_stress/main.cc b/repos/os/src/test/vfs_stress/main.cc index 30050497e5..f93332d61a 100644 --- a/repos/os/src/test/vfs_stress/main.cc +++ b/repos/os/src/test/vfs_stress/main.cc @@ -36,11 +36,11 @@ #include #include #include -#include -#include +#include #include +#include +#include #include -#include using namespace Genode; @@ -51,15 +51,15 @@ inline void assert_mkdir(Vfs::Directory_service::Mkdir_result r) switch (r) { case Result::MKDIR_OK: return; case Result::MKDIR_ERR_EXISTS: - PERR("MKDIR_ERR_EXISTS"); break; + error("MKDIR_ERR_EXISTS"); break; case Result::MKDIR_ERR_NO_ENTRY: - PERR("MKDIR_ERR_NO_ENTRY"); break; + error("MKDIR_ERR_NO_ENTRY"); break; case Result::MKDIR_ERR_NO_SPACE: - PERR("MKDIR_ERR_NO_SPACE"); break; + error("MKDIR_ERR_NO_SPACE"); break; case Result::MKDIR_ERR_NO_PERM: - PERR("MKDIR_ERR_NO_PERM"); break; + error("MKDIR_ERR_NO_PERM"); break; case Result::MKDIR_ERR_NAME_TOO_LONG: - PERR("MKDIR_ERR_NAME_TOO_LONG"); break; + error("MKDIR_ERR_NAME_TOO_LONG"); break; } throw Exception(); } @@ -70,15 +70,15 @@ inline void assert_open(Vfs::Directory_service::Open_result r) switch (r) { case Result::OPEN_OK: return; case Result::OPEN_ERR_NAME_TOO_LONG: - PERR("OPEN_ERR_NAME_TOO_LONG"); break; + error("OPEN_ERR_NAME_TOO_LONG"); break; case Result::OPEN_ERR_UNACCESSIBLE: - PERR("OPEN_ERR_UNACCESSIBLE"); break; + error("OPEN_ERR_UNACCESSIBLE"); break; case Result::OPEN_ERR_NO_SPACE: - PERR("OPEN_ERR_NO_SPACE"); break; + error("OPEN_ERR_NO_SPACE"); break; case Result::OPEN_ERR_NO_PERM: - PERR("OPEN_ERR_NO_PERM"); break; + error("OPEN_ERR_NO_PERM"); break; case Result::OPEN_ERR_EXISTS: - PERR("OPEN_ERR_EXISTS"); break; + error("OPEN_ERR_EXISTS"); break; } throw Exception(); } @@ -89,15 +89,15 @@ inline void assert_write(Vfs::File_io_service::Write_result r) switch (r) { case Result::WRITE_OK: return; case Result::WRITE_ERR_AGAIN: - PERR("WRITE_ERR_AGAIN"); break; + error("WRITE_ERR_AGAIN"); break; case Result::WRITE_ERR_WOULD_BLOCK: - PERR("WRITE_ERR_WOULD_BLOCK"); break; + error("WRITE_ERR_WOULD_BLOCK"); break; case Result::WRITE_ERR_INVALID: - PERR("WRITE_ERR_INVALID"); break; + error("WRITE_ERR_INVALID"); break; case Result::WRITE_ERR_IO: - PERR("WRITE_ERR_IO"); break; + error("WRITE_ERR_IO"); break; case Result::WRITE_ERR_INTERRUPT: - PERR("WRITE_ERR_INTERRUPT"); break; + error("WRITE_ERR_INTERRUPT"); break; } throw Exception(); } @@ -108,15 +108,15 @@ inline void assert_read(Vfs::File_io_service::Read_result r) switch (r) { case Result::READ_OK: return; case Result::READ_ERR_AGAIN: - PERR("READ_ERR_AGAIN"); break; + error("READ_ERR_AGAIN"); break; case Result::READ_ERR_WOULD_BLOCK: - PERR("READ_ERR_WOULD_BLOCK"); break; + error("READ_ERR_WOULD_BLOCK"); break; case Result::READ_ERR_INVALID: - PERR("READ_ERR_INVALID"); break; + error("READ_ERR_INVALID"); break; case Result::READ_ERR_IO: - PERR("READ_ERR_IO"); break; + error("READ_ERR_IO"); break; case Result::READ_ERR_INTERRUPT: - PERR("READ_ERR_INTERRUPT"); break; + error("READ_ERR_INTERRUPT"); break; } throw Exception(); } @@ -127,11 +127,11 @@ inline void assert_unlink(Vfs::Directory_service::Unlink_result r) switch (r) { case Result::UNLINK_OK: return; case Result::UNLINK_ERR_NO_ENTRY: - PERR("UNLINK_ERR_NO_ENTRY"); break; + error("UNLINK_ERR_NO_ENTRY"); break; case Result::UNLINK_ERR_NO_PERM: - PERR("UNLINK_ERR_NO_PERM"); break; + error("UNLINK_ERR_NO_PERM"); break; case Result::UNLINK_ERR_NOT_EMPTY: - PERR("UNLINK_ERR_NOT_EMPTY"); break; + error("UNLINK_ERR_NOT_EMPTY"); break; } throw Exception(); } @@ -141,25 +141,19 @@ static int MAX_DEPTH; typedef Genode::Path Path; -struct Stress_thread : public Genode::Thread_deprecated<4*1024*sizeof(Genode::addr_t)> +struct Stress_test { ::Path path; Vfs::file_size count; Vfs::File_system &vfs; - Stress_thread(Vfs::File_system &vfs, char const *parent, Affinity::Location affinity) - : Thread_deprecated(parent), path(parent), count(0), vfs(vfs) - { - Cpu_thread_client(cap()).affinity(affinity); - } + Stress_test(Vfs::File_system &vfs, char const *parent) + : path(parent), count(0), vfs(vfs) { } }; -struct Mkdir_thread : public Stress_thread +struct Mkdir_test : public Stress_test { - Mkdir_thread(Vfs::File_system &vfs, char const *parent, Affinity::Location affinity) - : Stress_thread(vfs, parent, affinity) { start(); } - void mkdir_b(int depth) { if (++depth > MAX_DEPTH) return; @@ -189,27 +183,23 @@ struct Mkdir_thread : public Stress_thread mkdir_a(depth); } - void entry() + Mkdir_test(Vfs::File_system &vfs, char const *parent) + : Stress_test(vfs, parent) { try { mkdir_a(1); } catch (...) { - PERR("failed at %s after %llu directories", path.base(), count); + error("failed at '",path,"' after ",count," directories"); } } int wait() { - join(); return count; } }; -struct Populate_thread : public Stress_thread +struct Populate_test : public Stress_test { - Populate_thread(Vfs::File_system &vfs, char const *parent, Affinity::Location affinity) - : Stress_thread(vfs, parent, affinity) { start(); } - - void populate(int depth) { if (++depth > MAX_DEPTH) return; @@ -241,12 +231,14 @@ struct Populate_thread : public Stress_thread return; default: - PERR("bad directory %c at the end of %s", dir_type, path.base()); + Genode::String<2> dir_name(&dir_type, 1); + error("bad directory '", dir_name, "' at the end of '", path, "'"); throw Exception(); } } - void entry() + Populate_test(Vfs::File_system &vfs, char const *parent) + : Stress_test(vfs, parent) { ::Path start_path(path.base()); try { @@ -257,23 +249,19 @@ struct Populate_thread : public Stress_thread path.append("/b"); populate(1); } catch (...) { - PERR("failed at %s after %llu files", path.base(), count); + error("failed at '", path, "' after ", count, " files"); } } int wait() { - join(); return count; } }; -struct Write_thread : public Stress_thread +struct Write_test : public Stress_test { - Write_thread(Vfs::File_system &vfs, char const *parent, Affinity::Location affinity) - : Stress_thread(vfs, parent, affinity) { start(); } - void write(int depth) { if (++depth > MAX_DEPTH) return; @@ -309,12 +297,14 @@ struct Write_thread : public Stress_thread return; default: - PERR("bad directory %c at the end of %s", dir_type, path.base()); + Genode::String<2> dir_name(&dir_type, 1); + error("bad directory ",dir_name," at the end of '", path, "'"); throw Exception(); } } - void entry() + Write_test(Vfs::File_system &vfs, char const *parent) + : Stress_test(vfs, parent) { size_t path_len = strlen(path.base()); try { @@ -325,23 +315,19 @@ struct Write_thread : public Stress_thread path.append("/b"); write(1); } catch (...) { - PERR("failed at %s after writing %llu bytes", path.base(), count); + error("failed at ",path," after writing ",count," bytes"); } } Vfs::file_size wait() { - join(); return count; } }; -struct Read_thread : public Stress_thread +struct Read_test : public Stress_test { - Read_thread(Vfs::File_system &vfs, char const *parent, Affinity::Location affinity) - : Stress_thread(vfs, parent, affinity) { start(); } - void read(int depth) { if (++depth > MAX_DEPTH) return; @@ -362,7 +348,7 @@ struct Read_thread : public Stress_thread file_size n; assert_read(handle->fs().read(handle, tmp, sizeof(tmp), n)); if (strcmp(path.base(), tmp, n)) - PERR("read returned bad data"); + error("read returned bad data"); count += n; } @@ -379,12 +365,14 @@ struct Read_thread : public Stress_thread return; default: - PERR("bad directory %c at the end of %s", dir_type, path.base()); + Genode::String<2> dir_name(&dir_type, 1); + error("bad directory ",dir_name," at the end of '", path, "'"); throw Exception(); } } - void entry() + Read_test(Vfs::File_system &vfs, char const *parent) + : Stress_test(vfs, parent) { size_t path_len = strlen(path.base()); try { @@ -395,23 +383,19 @@ struct Read_thread : public Stress_thread path.append("/b"); read(1); } catch (...) { - PERR("failed at %s after reading %llu bytes", path.base(), count); + error("failed at ",path," after reading ",count," bytes"); } } Vfs::file_size wait() { - join(); return count; } }; -struct Unlink_thread : public Stress_thread +struct Unlink_test : public Stress_test { - Unlink_thread(Vfs::File_system &vfs, char const *parent, Affinity::Location affinity) - : Stress_thread(vfs, parent, affinity) { start(); } - void empty_dir(char const *path) { ::Path subpath(path); @@ -423,7 +407,7 @@ struct Unlink_thread : public Stress_thread subpath.append(dirent.name); switch (dirent.type) { case Vfs::Directory_service::DIRENT_TYPE_END: - PERR("reached the end prematurely"); + error("reached the end prematurely"); throw Exception(); case Vfs::Directory_service::DIRENT_TYPE_DIRECTORY: @@ -434,7 +418,7 @@ struct Unlink_thread : public Stress_thread assert_unlink(vfs.unlink(subpath.base())); ++count; } catch (...) { - PERR("unlink %s failed", subpath.base()); + error("unlink ", subpath," failed"); throw; } subpath.strip_last_element(); @@ -442,19 +426,20 @@ struct Unlink_thread : public Stress_thread } } - void entry() + Unlink_test(Vfs::File_system &vfs, char const *parent) + : Stress_test(vfs, parent) { typedef Vfs::Directory_service::Unlink_result Result; try { Result r = vfs.unlink(path.base()); switch (r) { case Result::UNLINK_ERR_NOT_EMPTY: - PLOG("recursive unlink not supported"); + log("recursive unlink not supported"); empty_dir(path.base()); r = vfs.unlink(path.base()); case Result::UNLINK_OK: - PLOG("recursive unlink supported"); + log("recursive unlink supported"); ++count; return; @@ -462,27 +447,30 @@ struct Unlink_thread : public Stress_thread } assert_unlink(r); } catch (...) { - PERR("unlink %s failed", path.base()); + error("unlink ",path," failed"); } } int wait() { - join(); return count; } }; +void die(Genode::Env &env, int code) { env.parent().exit(code); } -int main() +void Component::construct(Genode::Env &env) { - static Vfs::Dir_file_system vfs_root(config()->xml_node().sub_node("vfs"), - Vfs::global_file_system_factory()); - static char path[Vfs::MAX_PATH_LEN]; + enum { ROOT_TREE_COUNT = 6 }; - MAX_DEPTH = config()->xml_node().attribute_value("depth", 16U); - unsigned thread_count = - config()->xml_node().attribute_value("threads", 6U); + Attached_rom_dataspace config_rom(env, "config"); + Xml_node const config_xml = config_rom.xml(); + + Vfs::Dir_file_system vfs_root(config_xml.sub_node("vfs"), + Vfs::global_file_system_factory()); + char path[Vfs::MAX_PATH_LEN]; + + MAX_DEPTH = config_xml.attribute_value("depth", 16U); unsigned long elapsed_ms; Timer::Connection timer; @@ -490,36 +478,29 @@ int main() /* populate the directory file system at / */ vfs_root.num_dirent("/"); - Affinity::Space space = env()->cpu_session()->affinity_space(); - - size_t initial_consumption = env()->ram_session()->used(); + size_t initial_consumption = env.ram().used(); /************************** ** Generate directories ** **************************/ { int count = 0; - Mkdir_thread *threads[thread_count]; - PLOG("generating directory surface..."); + log("generating directory surface..."); elapsed_ms = timer.elapsed_ms(); - for (size_t i = 0; i < thread_count; ++i) { - snprintf(path, 3, "/%zu", i); + for (int i = 0; i < ROOT_TREE_COUNT; ++i) { + snprintf(path, 3, "/%d", i); vfs_root.mkdir(path, 0); - threads[i] = new (Genode::env()->heap()) - Mkdir_thread(vfs_root, path, space.location_of_index(i)); - } - - for (size_t i = 0; i < thread_count; ++i) { - count += threads[i]->wait(); - destroy(Genode::env()->heap(), threads[i]); + Mkdir_test test(vfs_root, path); + count += test.wait(); } elapsed_ms = timer.elapsed_ms() - elapsed_ms; vfs_root.sync("/"); - PINF("created %d empty directories, %luμs/op , %zuKB consumed", - count, (elapsed_ms*1000)/count, env()->ram_session()->used()/1024); + log("created ",count," empty directories, ", + (elapsed_ms*1000)/count,"μs/op , ", + env.ram().used()/1024,"KB consumed"); } @@ -528,27 +509,22 @@ int main() ********************/ { int count = 0; - Populate_thread *threads[thread_count]; - PLOG("generating files..."); + log("generating files..."); elapsed_ms = timer.elapsed_ms(); - for (size_t i = 0; i < thread_count; ++i) { - snprintf(path, 3, "/%zu", i); - threads[i] = new (Genode::env()->heap()) - Populate_thread(vfs_root, path, space.location_of_index(i)); - } - - for (size_t i = 0; i < thread_count; ++i) { - count += threads[i]->wait(); - destroy(Genode::env()->heap(), threads[i]); + for (int i = 0; i < ROOT_TREE_COUNT; ++i) { + snprintf(path, 3, "/%d", i); + Populate_test test(vfs_root, path); + count += test.wait(); } elapsed_ms = timer.elapsed_ms() - elapsed_ms; vfs_root.sync("/"); - PINF("created %d empty files, %luμs/op, %zuKB consumed", - count, (elapsed_ms*1000)/count, env()->ram_session()->used()/1024); + log("created ",count," empty files, ", + (elapsed_ms*1000)/count,"μs/op, ", + env.ram().used()/1024,"KB consumed"); } @@ -556,37 +532,30 @@ int main() ** Write files ** *****************/ - if (!config()->xml_node().attribute_value("write", true)) { + if (!config_xml.attribute_value("write", true)) { elapsed_ms = timer.elapsed_ms(); - - PINF("total: %lums, %zuK consumed", - elapsed_ms, env()->ram_session()->used()/1024); - - return 0; + log("total: ",elapsed_ms,"ms, ",env.ram().used()/1024,"K consumed"); + return die(env, 0); } { Vfs::file_size count = 0; - Write_thread *threads[thread_count]; - PLOG("writing files..."); + log("writing files..."); elapsed_ms = timer.elapsed_ms(); - for (size_t i = 0; i < thread_count; ++i) { - snprintf(path, 3, "/%zu", i); - threads[i] = new (Genode::env()->heap()) - Write_thread(vfs_root, path, space.location_of_index(i)); - } + for (int i = 0; i < ROOT_TREE_COUNT; ++i) { + snprintf(path, 3, "/%d", i); + Write_test test(vfs_root, path); + count += test.wait(); - for (size_t i = 0; i < thread_count; ++i) { - count += threads[i]->wait(); - destroy(Genode::env()->heap(), threads[i]); } elapsed_ms = timer.elapsed_ms() - elapsed_ms; vfs_root.sync("/"); - PINF("wrote %llu bytes %llukB/s, %zuKB consumed", - count, count/elapsed_ms, env()->ram_session()->used()/1024); + log("wrote ",count," bytes ", + count/elapsed_ms,"kB/s, ", + env.ram().used()/1024,"KB consumed"); } @@ -594,37 +563,30 @@ int main() ** Read files ** *****************/ - if (!config()->xml_node().attribute_value("read", true)) { + if (!config_xml.attribute_value("read", true)) { elapsed_ms = timer.elapsed_ms(); - PINF("total: %lums, %zuKB consumed", - elapsed_ms, env()->ram_session()->used()/1024); - - return 0; + log("total: ",elapsed_ms,"ms, ",env.ram().used()/1024,"KB consumed"); + return die(env, 0); } { Vfs::file_size count = 0; - Read_thread *threads[thread_count]; - PLOG("reading files..."); + log("reading files..."); elapsed_ms = timer.elapsed_ms(); - for (size_t i = 0; i < thread_count; ++i) { - snprintf(path, 3, "/%zu", i); - threads[i] = new (Genode::env()->heap()) - Read_thread(vfs_root, path, space.location_of_index(i)); - } - - for (size_t i = 0; i < thread_count; ++i) { - count += threads[i]->wait(); - destroy(Genode::env()->heap(), threads[i]); + for (int i = 0; i < ROOT_TREE_COUNT; ++i) { + snprintf(path, 3, "/%d", i); + Read_test test(vfs_root, path); + count += test.wait(); } elapsed_ms = timer.elapsed_ms() - elapsed_ms; vfs_root.sync("/"); - PINF("read %llu bytes, %llukB/s, %zuKB consumed", - count, count/elapsed_ms, env()->ram_session()->used()/1024); + log("read ",count," bytes, ", + count/elapsed_ms,"kB/s, ", + env.ram().used()/1024,"KB consumed"); } @@ -632,50 +594,43 @@ int main() ** Unlink files ** ******************/ - if (!config()->xml_node().attribute_value("unlink", true)) { + if (!config_xml.attribute_value("unlink", true)) { elapsed_ms = timer.elapsed_ms(); + log("total: ",elapsed_ms,"ms, ",env.ram().used()/1024,"KB consumed"); + return die(env, 0); - PINF("total: %lums, %zuKB consumed", - elapsed_ms, env()->ram_session()->used()/1024); - - return 0; } { Vfs::file_size count = 0; - Unlink_thread *threads[thread_count]; - PLOG("unlink files..."); + log("unlink files..."); elapsed_ms = timer.elapsed_ms(); - for (size_t i = 0; i < thread_count; ++i) { - snprintf(path, 3, "/%zu", i); - threads[i] = new (Genode::env()->heap()) - Unlink_thread(vfs_root, path, space.location_of_index(i)); - } + for (int i = 0; i < ROOT_TREE_COUNT; ++i) { + snprintf(path, 3, "/%d", i); + Unlink_test test(vfs_root, path); + count += test.wait(); - for (size_t i = 0; i < thread_count; ++i) { - count += threads[i]->wait(); - destroy(Genode::env()->heap(), threads[i]); } elapsed_ms = timer.elapsed_ms() - elapsed_ms; vfs_root.sync("/"); - PINF("unlinked %llu files in %lums, %zuKB consumed", - count, elapsed_ms, env()->ram_session()->used()/1024); + log("unlinked ",count," files in ",elapsed_ms,"ms, ", + env.ram().used()/1024,"KB consumed"); } - PINF("total: %lums, %zuKB consumed", - timer.elapsed_ms(), env()->ram_session()->used()/1024); + log("total: ",timer.elapsed_ms(),"ms, ", + env.ram().used()/1024,"KB consumed"); - size_t outstanding = env()->ram_session()->used() - initial_consumption; + size_t outstanding = env.ram().used() - initial_consumption; if (outstanding) { if (outstanding < 1024) - PERR("%zuB not freed after unlink and sync!", outstanding); + error(outstanding, "B not freed after unlink and sync!"); else - PERR("%zuKB not freed after unlink and sync!", outstanding/1024); + error(outstanding/1024,"KB not freed after unlink and sync!"); } - return 0; + die(env, 0); }