diff --git a/docs/manual/commandline.qbk b/docs/manual/commandline.qbk index cda8824d8cf2..ac50cf513b3d 100644 --- a/docs/manual/commandline.qbk +++ b/docs/manual/commandline.qbk @@ -122,6 +122,9 @@ described in the table below: log channel and send all parcel transport logs to the target destination (default: cout)]] + [[`--hpx:debug-timing-log [arg]`] [enable all messages on the timing log + channel and send all timing logs to the + target destination (default: cout)]] [[`--hpx:debug-clp`] [debug command line processing]] [[`--hpx:attach-debugger arg`] [wait for a debugger to be attached, possible arg values: `startup` or `exception` (default: startup)]] diff --git a/hpx/runtime.hpp b/hpx/runtime.hpp index 4a1f542497aa..cdbeb707ab46 100644 --- a/hpx/runtime.hpp +++ b/hpx/runtime.hpp @@ -373,7 +373,7 @@ namespace hpx void deinit_tss(); public: - void set_state(state s) { state_.store(s); } + void set_state(state s); protected: util::reinit_helper reinit_; diff --git a/hpx/runtime_impl.hpp b/hpx/runtime_impl.hpp index 03a07c72b8de..4478eb05ca36 100644 --- a/hpx/runtime_impl.hpp +++ b/hpx/runtime_impl.hpp @@ -21,7 +21,6 @@ #include #include #include -#include #include #include #include @@ -386,7 +385,6 @@ namespace hpx boost::scoped_ptr thread_manager_; parcelset::parcelhandler parcel_handler_; naming::resolver_client agas_client_; - util::detail::init_logging init_logging_; applier::applier applier_; boost::signals2::scoped_connection default_error_sink_; diff --git a/hpx/util/block_profiler.hpp b/hpx/util/block_profiler.hpp index ac797554af49..051027b9f2fa 100644 --- a/hpx/util/block_profiler.hpp +++ b/hpx/util/block_profiler.hpp @@ -1,4 +1,4 @@ -// Copyright (c) 2007-2012 Hartmut Kaiser +// Copyright (c) 2007-2017 Hartmut Kaiser // // Distributed under the Boost Software License, Version 1.0. (See accompanying // file LICENSE_1_0.txt or copy at http://www.boost.org/LICENSE_1_0.txt) @@ -58,7 +58,7 @@ namespace hpx { namespace util void print_stats() { - LTIM_(fatal) << "profiler: " << description_ << ": " + LTIM_(error) << "profiler: " << description_ << ": " << boost::accumulators::sum(totals_) << " (" << boost::accumulators::count(totals_) << ", " << boost::accumulators::mean(totals_) << ", " @@ -126,7 +126,7 @@ namespace hpx { namespace util void print_stats() { - LTIM_(fatal) << "profiler: " << description_ << ": " + LTIM_(error) << "profiler: " << description_ << ": " << extract_count(totals_) << ", " << extract_mean(totals_); } @@ -214,13 +214,13 @@ namespace hpx { namespace util // special interface for block_profiler_wrapper below void measure(double started) { - if (enable_logging_ && LTIM_ENABLED(fatal)) + if (enable_logging_ && LTIM_ENABLED(error)) stats_.add(started); } double elapsed() { - return enable_logging_ && LTIM_ENABLED(fatal) ? stats_.elapsed() : 0; + return enable_logging_ && LTIM_ENABLED(error) ? stats_.elapsed() : 0; } private: diff --git a/hpx/util/init_logging.hpp b/hpx/util/init_logging.hpp index ae7733193a3b..d084a511b06b 100644 --- a/hpx/util/init_logging.hpp +++ b/hpx/util/init_logging.hpp @@ -1,4 +1,4 @@ -// Copyright (c) 2007-2013 Hartmut Kaiser +// Copyright (c) 2007-2017 Hartmut Kaiser // // Distributed under the Boost Software License, Version 1.0. (See accompanying // file LICENSE_1_0.txt or copy at http://www.boost.org/LICENSE_1_0.txt) @@ -6,7 +6,6 @@ #if !defined(HPX_UTIL_AGAS_INIT_LOGGING_SEP_07_2013_0754PM) #define HPX_UTIL_AGAS_INIT_LOGGING_SEP_07_2013_0754PM -#include #include #include #include @@ -18,11 +17,7 @@ namespace hpx { namespace util { namespace detail { // the init_logging type will be used for initialization purposes only as // well - struct init_logging - { - init_logging(runtime_configuration& ini, bool isconsole, - agas::addressing_service& agas_client); - }; + HPX_API_EXPORT void init_logging(runtime_configuration& ini, bool isconsole); }}} #endif diff --git a/hpx/util/logging.hpp b/hpx/util/logging.hpp index a32085046793..003be9edf657 100644 --- a/hpx/util/logging.hpp +++ b/hpx/util/logging.hpp @@ -1,4 +1,4 @@ -// Copyright (c) 2007-2013 Hartmut Kaiser +// Copyright (c) 2007-2017 Hartmut Kaiser // // Distributed under the Boost Software License, Version 1.0. (See accompanying // file LICENSE_1_0.txt or copy at http://www.boost.org/LICENSE_1_0.txt) @@ -16,8 +16,22 @@ #include #include +#include + HPX_LOG_FORMAT_MSG(optimize::cache_string_one_str<>) +/////////////////////////////////////////////////////////////////////////////// +// specific logging +#define LTM_(lvl) LHPX_(lvl, " [TM] ") /* thread manager */ +#define LRT_(lvl) LHPX_(lvl, " [RT] ") /* runtime support */ +#define LOSH_(lvl) LHPX_(lvl, " [OSH] ") /* one size heap */ +#define LERR_(lvl) LHPX_(lvl, " [ERR] ") /* exceptions */ +#define LLCO_(lvl) LHPX_(lvl, " [LCO] ") /* lcos */ +#define LPCS_(lvl) LHPX_(lvl, " [PCS] ") /* performance counters */ +#define LAS_(lvl) LHPX_(lvl, " [AS] ") /* addressing service */ +#define LBT_(lvl) LHPX_(lvl, " [BT] ") /* bootstrap */ +#define LSEC_(lvl) LHPX_(lvl, " [SEC] ") /* security */ + /////////////////////////////////////////////////////////////////////////////// namespace hpx { namespace util { @@ -65,6 +79,11 @@ namespace hpx { namespace util hpx::util::timing_level(), lvl) \ << hpx::util::levelname(::hpx::util::logging::level::lvl) << " " \ /**/ + #define LPROGRESS_ \ + HPX_LOG_USE_LOG_IF_LEVEL(hpx::util::timing_logger(), \ + hpx::util::timing_level(), fatal) << " " \ + << __FILE__ << ":" << __LINE__ << " " << BOOST_CURRENT_FUNCTION << " "\ + /**/ #define LTIM_ENABLED(lvl) \ hpx::util::timing_level()->is_enabled(::hpx::util::logging::level::lvl)\ @@ -209,6 +228,19 @@ namespace hpx { namespace util hpx::util::logging::level::error)) \ /**/ +// helper type to forward logging during bootstrap to two destinations +struct bootstrap_logging { constexpr bootstrap_logging() {} }; + +template +bootstrap_logging const& operator<< (bootstrap_logging const& l, T const& t) +{ + LBT_(info) << t; + LPROGRESS_ << t; + return l; +} + +constexpr bootstrap_logging lbt_; + #else // logging is disabled all together @@ -219,15 +251,28 @@ namespace hpx { namespace util { namespace detail // with logging specific data HPX_EXPORT std::vector get_logging_data(); - struct dummy_log_impl {}; - HPX_EXPORT extern dummy_log_impl dummy_log; + struct dummy_log_impl { constexpr dummy_log_impl() {} }; + constexpr dummy_log_impl dummy_log; template - inline dummy_log_impl& operator<<(dummy_log_impl& l, T&&) { return l; } + dummy_log_impl const& operator<<(dummy_log_impl const& l, T&&) + { + return l; + } + + struct bootstrap_logging { constexpr bootstrap_logging() {} }; + constexpr bootstrap_logging lbt_; + + template + bootstrap_logging const& operator<< (bootstrap_logging const& l, T&&) + { + return l; + } #define LAGAS_(lvl) if(true) {} else hpx::util::detail::dummy_log #define LPT_(lvl) if(true) {} else hpx::util::detail::dummy_log #define LTIM_(lvl) if(true) {} else hpx::util::detail::dummy_log + #define LPROGRESS_ if(true) {} else hpx::util::detail::dummy_log #define LHPX_(lvl, cat) if(true) {} else hpx::util::detail::dummy_log #define LAPP_(lvl) if(true) {} else hpx::util::detail::dummy_log #define LDEB_ if(true) {} else hpx::util::detail::dummy_log @@ -250,19 +295,6 @@ namespace hpx { namespace util { namespace detail }}} #endif - -/////////////////////////////////////////////////////////////////////////////// -// specific logging -#define LTM_(lvl) LHPX_(lvl, " [TM] ") /* thread manager */ -#define LRT_(lvl) LHPX_(lvl, " [RT] ") /* runtime support */ -#define LOSH_(lvl) LHPX_(lvl, " [OSH] ") /* one size heap */ -#define LERR_(lvl) LHPX_(lvl, " [ERR] ") /* exceptions */ -#define LLCO_(lvl) LHPX_(lvl, " [LCO] ") /* lcos */ -#define LPCS_(lvl) LHPX_(lvl, " [PCS] ") /* performance counters */ -#define LAS_(lvl) LHPX_(lvl, " [AS] ") /* addressing service */ -#define LBT_(lvl) LHPX_(lvl, " [BT] ") /* bootstrap */ -#define LSEC_(lvl) LHPX_(lvl, " [SEC] ") /* security */ - #endif diff --git a/src/hpx_init.cpp b/src/hpx_init.cpp index e43702330e54..d4df07e715fa 100644 --- a/src/hpx_init.cpp +++ b/src/hpx_init.cpp @@ -25,6 +25,8 @@ #include #include #include +#include +#include #include #include @@ -692,6 +694,8 @@ namespace hpx boost::program_options::variables_map& vm, runtime_mode mode, startup_function_type startup, shutdown_function_type shutdown) { + LPROGRESS_; + add_startup_functions(rt, vm, mode, std::move(startup), std::move(shutdown)); @@ -709,6 +713,8 @@ namespace hpx boost::program_options::variables_map& vm, runtime_mode mode, startup_function_type startup, shutdown_function_type shutdown) { + LPROGRESS_; + add_startup_functions(rt, vm, mode, std::move(startup), std::move(shutdown)); @@ -764,6 +770,8 @@ namespace hpx threads::policies::init_affinity_data affinity_init( pu_offset, pu_step, affinity_domain, affinity_desc); + LPROGRESS_ << "run_local: create runtime"; + // Build and configure this runtime instance. typedef hpx::runtime_impl runtime_type; std::unique_ptr rt( @@ -806,6 +814,8 @@ namespace hpx threads::policies::init_affinity_data affinity_init( pu_offset, pu_step, affinity_domain, affinity_desc); + LPROGRESS_ << "run_throttle: create runtime"; + // Build and configure this runtime instance. typedef hpx::runtime_impl runtime_type; std::unique_ptr rt( @@ -852,6 +862,8 @@ namespace hpx threads::policies::init_affinity_data affinity_init( pu_offset, pu_step, affinity_domain, affinity_desc); + LPROGRESS_ << "run_static_priority: create runtime"; + // Build and configure this runtime instance. typedef hpx::runtime_impl runtime_type; std::unique_ptr rt( @@ -896,6 +908,8 @@ namespace hpx threads::policies::init_affinity_data affinity_init( pu_offset, pu_step, affinity_domain, affinity_desc); + LPROGRESS_ << "run_static: create runtime"; + // Build and configure this runtime instance. typedef hpx::runtime_impl runtime_type; std::unique_ptr rt( @@ -942,6 +956,8 @@ namespace hpx threads::policies::init_affinity_data affinity_init( pu_offset, pu_step, affinity_domain, affinity_desc); + LPROGRESS_ << "run_priority_local: create runtime"; + // Build and configure this runtime instance. typedef hpx::runtime_impl runtime_type; std::unique_ptr rt( @@ -975,6 +991,8 @@ namespace hpx cfg.num_threads_, num_high_priority_queues, 1000, cfg.numa_sensitive_, "core-abp_fifo_priority_queue_scheduler"); + LPROGRESS_ << "run_priority_abp: create runtime"; + // Build and configure this runtime instance. typedef hpx::runtime_impl runtime_type; std::unique_ptr rt( @@ -1011,6 +1029,8 @@ namespace hpx queue_policy::init_parameter_type init(cfg.num_threads_, arity, 1000, 0, "core-hierarchy_scheduler"); + LPROGRESS_ << "run_hierarchy: create runtime"; + // Build and configure this runtime instance. typedef hpx::runtime_impl runtime_type; std::unique_ptr rt( @@ -1047,6 +1067,8 @@ namespace hpx num_high_priority_queues, 1000, cfg.numa_sensitive_, "core-periodic_priority_queue_scheduler"); + LPROGRESS_ << "run_periodic: create runtime"; + // Build and configure this runtime instance. typedef hpx::runtime_impl runtime_type; std::unique_ptr rt( @@ -1092,7 +1114,6 @@ namespace hpx unsetenv("LC_IDENTIFICATION"); unsetenv("LC_ALL"); #endif - try { // make sure the runtime system is not active yet if (get_runtime_ptr() != nullptr) @@ -1114,6 +1135,10 @@ namespace hpx return result; } + // initialize logging + util::detail::init_logging(cfg.rtcfg_, + cfg.mode_ == runtime_mode_console); + util::apex_wrapper_init apex(argc, argv); // Initialize and start the HPX runtime. diff --git a/src/pre_main.cpp b/src/pre_main.cpp index 0716a46be5b1..4576fb4238c2 100644 --- a/src/pre_main.cpp +++ b/src/pre_main.cpp @@ -51,20 +51,20 @@ namespace hpx static void register_counter_types() { naming::get_agas_client().register_counter_types(); - LBT_(info) << "(2nd stage) pre_main: registered AGAS client-side " - "performance counter types"; + lbt_ << "(2nd stage) pre_main: registered AGAS client-side " + "performance counter types"; get_runtime().register_counter_types(); - LBT_(info) << "(2nd stage) pre_main: registered runtime performance " - "counter types"; + lbt_ << "(2nd stage) pre_main: registered runtime performance " + "counter types"; threads::get_thread_manager().register_counter_types(); - LBT_(info) << "(2nd stage) pre_main: registered thread-manager performance " - "counter types"; + lbt_ << "(2nd stage) pre_main: registered thread-manager performance " + "counter types"; applier::get_applier().get_parcel_handler().register_counter_types(); - LBT_(info) << "(2nd stage) pre_main: registered parcelset performance " - "counter types"; + lbt_ << "(2nd stage) pre_main: registered parcelset performance " + "counter types"; } /////////////////////////////////////////////////////////////////////////////// @@ -99,13 +99,13 @@ int pre_main(runtime_mode mode) int exit_code = 0; if (runtime_mode_connect == mode) { - LBT_(info) << "(2nd stage) pre_main: locality is in connect mode, " - "skipping 2nd and 3rd stage startup synchronization"; - LBT_(info) << "(2nd stage) pre_main: addressing services enabled"; + lbt_ << "(2nd stage) pre_main: locality is in connect mode, " + "skipping 2nd and 3rd stage startup synchronization"; + lbt_ << "(2nd stage) pre_main: addressing services enabled"; // Load components, so that we can use the barrier LCO. exit_code = runtime_support::load_components(find_here()); - LBT_(info) << "(2nd stage) pre_main: loaded components" + lbt_ << "(2nd stage) pre_main: loaded components" << (exit_code ? ", application exit has been requested" : ""); // Work on registration requests for message handler plugins @@ -117,19 +117,19 @@ int pre_main(runtime_mode mode) rt.set_state(state_pre_startup); runtime_support::call_startup_functions(find_here(), true); - LBT_(info) << "(3rd stage) pre_main: ran pre-startup functions"; + lbt_ << "(3rd stage) pre_main: ran pre-startup functions"; rt.set_state(state_startup); runtime_support::call_startup_functions(find_here(), false); - LBT_(info) << "(3rd stage) pre_main: ran startup functions"; + lbt_ << "(3rd stage) pre_main: ran startup functions"; } else { - LBT_(info) << "(2nd stage) pre_main: addressing services enabled"; + lbt_ << "(2nd stage) pre_main: addressing services enabled"; // Load components, so that we can use the barrier LCO. exit_code = runtime_support::load_components(find_here()); - LBT_(info) << "(2nd stage) pre_main: loaded components" + lbt_ << "(2nd stage) pre_main: loaded components" << (exit_code ? ", application exit has been requested" : ""); // {{{ Second and third stage barrier creation. @@ -143,13 +143,11 @@ int pre_main(runtime_mode mode) , "no console locality registered"); } - LBT_(info) << "(2nd stage) pre_main: created \ - 2nd and 3rd stage boot barriers"; + lbt_ << "(2nd stage) pre_main: created 2nd and 3rd stage boot barriers"; } else // Hosted. { - LBT_(info) - << "(2nd stage) pre_main: found 2nd and 3rd stage boot barriers"; + lbt_ << "(2nd stage) pre_main: found 2nd and 3rd stage boot barriers"; } // }}} @@ -169,30 +167,30 @@ int pre_main(runtime_mode mode) // localities, ensuring that the component namespace tables are fully // populated before user code is executed. lcos::barrier::synchronize(); - LBT_(info) << "(2nd stage) pre_main: passed 2nd stage boot barrier"; + lbt_ << "(2nd stage) pre_main: passed 2nd stage boot barrier"; runtime_support::call_startup_functions(find_here(), true); - LBT_(info) << "(3rd stage) pre_main: ran pre-startup functions"; + lbt_ << "(3rd stage) pre_main: ran pre-startup functions"; // Third stage separates pre-startup and startup function phase. lcos::barrier::synchronize(); - LBT_(info) << "(3rd stage) pre_main: passed 3rd stage boot barrier"; + lbt_ << "(3rd stage) pre_main: passed 3rd stage boot barrier"; runtime_support::call_startup_functions(find_here(), false); - LBT_(info) << "(4th stage) pre_main: ran startup functions"; + lbt_ << "(4th stage) pre_main: ran startup functions"; // Forth stage bootstrap synchronizes startup functions across all // localities. This is done after component loading to guarantee that // all user code, including startup functions, are only run after the // component tables are populated. lcos::barrier::synchronize(); - LBT_(info) << "(4th stage) pre_main: passed 4th stage boot barrier"; + lbt_ << "(4th stage) pre_main: passed 4th stage boot barrier"; } // Enable logging. Even if we terminate at this point we will see all // pending log messages so far. components::activate_logging(); - LBT_(info) << "(4th stage) pre_main: activated logging"; + lbt_ << "(4th stage) pre_main: activated logging"; // Any error in post-command line handling or any explicit --exit command // line option will cause the application to terminate at this point. diff --git a/src/runtime.cpp b/src/runtime.cpp index fdbd285a6d28..417e98d259a5 100644 --- a/src/runtime.cpp +++ b/src/runtime.cpp @@ -27,6 +27,7 @@ #include #include #include +#include #include #include #include @@ -221,7 +222,7 @@ namespace hpx "state_starting", // 4 "state_running", // 5 "state_suspended", // 6 - "state_pre_shutdown" // 7 + "state_pre_shutdown", // 7 "state_shutdown", // 8 "state_stopping", // 9 "state_terminating", // 10 @@ -513,6 +514,8 @@ namespace hpx , security_data_(new detail::manage_security_data) #endif { + LPROGRESS_; + // initialize our TSS runtime::init_tss(); util::reinit_construct(); // call only after TLS was initialized @@ -527,6 +530,12 @@ namespace hpx --instance_number_counter_; } + void runtime::set_state(state s) + { + LPROGRESS_ << get_runtime_state_name(s); + state_.store(s); + } + /////////////////////////////////////////////////////////////////////////// boost::atomic runtime::instance_number_counter_(-1); diff --git a/src/runtime/agas/addressing_service.cpp b/src/runtime/agas/addressing_service.cpp index 0ebbc3e9c252..c4ec39433a1f 100644 --- a/src/runtime/agas/addressing_service.cpp +++ b/src/runtime/agas/addressing_service.cpp @@ -1,6 +1,6 @@ //////////////////////////////////////////////////////////////////////////////// // Copyright (c) 2011 Bryce Adelstein-Lelbach -// Copyright (c) 2011-2016 Hartmut Kaiser +// Copyright (c) 2011-2017 Hartmut Kaiser // Copyright (c) 2016 Parsa Amini // Copyright (c) 2016 Thomas Heller // @@ -146,6 +146,8 @@ addressing_service::addressing_service( , state_(state_starting) , locality_() { // {{{ + LPROGRESS_; + std::shared_ptr pp = ph.get_bootstrap_parcelport(); create_big_boot_barrier(pp ? pp.get() : nullptr, ph.endpoints(), ini_); diff --git a/src/runtime/agas/interface.cpp b/src/runtime/agas/interface.cpp index 7b415242a3f9..cb959235eed3 100644 --- a/src/runtime/agas/interface.cpp +++ b/src/runtime/agas/interface.cpp @@ -366,6 +366,10 @@ naming::id_type get_console_locality( error_code& ec ) { + runtime* rt = get_runtime_ptr(); + if (rt == nullptr || rt->get_state() == state_invalid) + return naming::invalid_id; + naming::gid_type console; naming::get_agas_client().get_console_locality(console, ec); if (ec) return naming::invalid_id; @@ -375,7 +379,8 @@ naming::id_type get_console_locality( std::uint32_t get_locality_id(error_code& ec) { - if (get_runtime_ptr() == nullptr) + runtime* rt = get_runtime_ptr(); + if (rt == nullptr || rt->get_state() == state_invalid) return naming::invalid_locality_id; naming::gid_type l = naming::get_agas_client().get_local_locality(ec); @@ -388,7 +393,8 @@ naming::gid_type get_next_id( , error_code& ec ) { - if (get_runtime_ptr() == nullptr) + runtime* rt = get_runtime_ptr(); + if (rt == nullptr || rt->get_state() == state_invalid) { HPX_THROWS_IF(ec, invalid_status, "get_next_id", "the runtime system has not been started yet."); diff --git a/src/runtime/components/console_logging.cpp b/src/runtime/components/console_logging.cpp index 2cdc8fb840f6..9d5b92b44e49 100644 --- a/src/runtime/components/console_logging.cpp +++ b/src/runtime/components/console_logging.cpp @@ -96,7 +96,8 @@ namespace hpx { namespace components bool pending_logs::is_active() { - return threads::threadmanager_is(state_running) && threads::get_self_ptr() && + return threads::get_self_ptr() && + threads::threadmanager_is(state_running) && activated_.load(); } diff --git a/src/runtime/parcelset/parcelhandler.cpp b/src/runtime/parcelset/parcelhandler.cpp index 1485b1b1c2f7..632bcbf0a6a7 100644 --- a/src/runtime/parcelset/parcelhandler.cpp +++ b/src/runtime/parcelset/parcelhandler.cpp @@ -1,4 +1,4 @@ -// Copyright (c) 2007-2016 Hartmut Kaiser +// Copyright (c) 2007-2017 Hartmut Kaiser // Copyright (c) 2013-2014 Thomas Heller // Copyright (c) 2007 Richard D Guidry Jr // Copyright (c) 2011 Bryce Lelbach & Katelyn Kufahl @@ -34,6 +34,7 @@ #include #include #include +#include #include @@ -109,6 +110,8 @@ namespace hpx { namespace parcelset count_routed_(0), write_handler_(&default_write_handler) { + LPROGRESS_; + for (plugins::parcelport_factory_base* factory : get_parcelport_factories()) { std::shared_ptr pp; diff --git a/src/runtime_impl.cpp b/src/runtime_impl.cpp index 4d585779f7a8..3395e5166f01 100644 --- a/src/runtime_impl.cpp +++ b/src/runtime_impl.cpp @@ -160,9 +160,10 @@ namespace hpx { util::placeholders::_1, util::placeholders::_2, true), util::bind(&runtime_impl::deinit_tss, This())), agas_client_(parcel_handler_, ini_, mode_), - init_logging_(ini_, mode_ == runtime_mode_console, agas_client_), applier_(parcel_handler_, *thread_manager_) { + LPROGRESS_; + components::server::get_error_dispatcher().register_error_sink( &runtime_impl::default_errorsink, default_error_sink_); @@ -234,6 +235,8 @@ namespace hpx { runtime_support_->tidy(); LRT_(debug) << "~runtime_impl(finished)"; + + LPROGRESS_; } int pre_main(hpx::runtime_mode); @@ -243,7 +246,7 @@ namespace hpx { runtime_impl::run_helper( util::function_nonser func, int& result) { - LBT_(info) << "(2nd stage) runtime_impl::run_helper: launching pre_main"; + lbt_ << "(2nd stage) runtime_impl::run_helper: launching pre_main"; // Change our thread description, as we're about to call pre_main threads::set_thread_description(threads::get_self_id(), "pre_main"); @@ -251,12 +254,12 @@ namespace hpx { // Finish the bootstrap result = hpx::pre_main(mode_); if (result) { - LBT_(info) << "runtime_impl::run_helper: bootstrap " - "aborted, bailing out"; + lbt_ << "runtime_impl::run_helper: bootstrap " + "aborted, bailing out"; return threads::thread_result_type(threads::terminated, nullptr); } - LBT_(info) << "(4th stage) runtime_impl::run_helper: bootstrap complete"; + lbt_ << "(4th stage) runtime_impl::run_helper: bootstrap complete"; set_state(state_running); parcel_handler_.enable_alternative_parcelports(); @@ -310,23 +313,23 @@ namespace hpx { LRT_(info) << "cmd_line: " << get_config().get_cmd_line(); - LBT_(info) << "(1st stage) runtime_impl::start: booting locality " //-V128 + lbt_ << "(1st stage) runtime_impl::start: booting locality " //-V128 << here() << " on " << num_threads_ << " OS-thread" << ((num_threads_ == 1) ? "" : "s"); // start runtime_support services runtime_support_->run(); - LBT_(info) << "(1st stage) runtime_impl::start: started " + lbt_ << "(1st stage) runtime_impl::start: started " "runtime_support component"; // start the io pool io_pool_.run(false); - LBT_(info) << "(1st stage) runtime_impl::start: started the application " + lbt_ << "(1st stage) runtime_impl::start: started the application " "I/O service pool"; // start the thread manager thread_manager_->run(num_threads_); - LBT_(info) << "(1st stage) runtime_impl::start: started threadmanager"; + lbt_ << "(1st stage) runtime_impl::start: started threadmanager"; // }}} // invoke the AGAS v2 notifications @@ -334,7 +337,7 @@ namespace hpx { // {{{ launch main // register the given main function with the thread manager - LBT_(info) << "(1st stage) runtime_impl::start: launching run_helper " + lbt_ << "(1st stage) runtime_impl::start: launching run_helper " "HPX thread"; threads::thread_init_data data( diff --git a/src/util/command_line_handling.cpp b/src/util/command_line_handling.cpp index d1bbb499ab7c..c8630e6a7cfd 100644 --- a/src/util/command_line_handling.cpp +++ b/src/util/command_line_handling.cpp @@ -788,6 +788,7 @@ namespace hpx { namespace util if (vm.count("hpx:run-agas-server-only")) ini_config += "hpx.agas.dedicated_server=1"; +#if defined(HPX_HAVE_LOGGING) if (vm.count("hpx:debug-hpx-log")) { ini_config += "hpx.logging.console.destination=" + detail::convert_to_log_file( @@ -821,6 +822,29 @@ namespace hpx { namespace util ini_config += "hpx.logging.parcel.level=5"; } + if (vm.count("hpx:debug-timing-log")) { + ini_config += "hpx.logging.console.timing.destination=" + + detail::convert_to_log_file( + vm["hpx:debug-timing-log"].as()); + ini_config += "hpx.logging.timing.destination=" + + detail::convert_to_log_file( + vm["hpx:debug-timing-log"].as()); + ini_config += "hpx.logging.console.timing.level=1"; + ini_config += "hpx.logging.timing.level=1"; + } +#else + if (vm.count("hpx:debug-hpx-log") || + vm.count("hpx:debug-agas-log") || + vm.count("hpx:debug-parcel-log") || + vm.count("hpx:debug-timing-log")) + { + throw hpx::detail::command_line_error( + "Command line option error: can't enable logging while it " + "was disabled at configuration time. Please re-configure " + "HPX using the option -DHPX_WITH_LOGGING=On."); + } +#endif + // Set number of cores and OS threads in configuration. ini_config += "hpx.os_threads=" + std::to_string(num_threads_); diff --git a/src/util/io_service_pool.cpp b/src/util/io_service_pool.cpp index 9766cf71e86b..51e771622e4e 100644 --- a/src/util/io_service_pool.cpp +++ b/src/util/io_service_pool.cpp @@ -1,4 +1,4 @@ -// Copyright (c) 2007-2015 Hartmut Kaiser +// Copyright (c) 2007-2017 Hartmut Kaiser // Copyright (c) 2011 Bryce Adelstein-Lelbach // // Parts of this code were taken from the Boost.Asio library @@ -13,6 +13,7 @@ #include #include #include +#include #include #include @@ -35,6 +36,8 @@ namespace hpx { namespace util on_start_thread_(on_start_thread), on_stop_thread_(on_stop_thread), pool_name_(pool_name), pool_name_postfix_(name_postfix) { + LPROGRESS_ << pool_name; + if (pool_size == 0) { HPX_THROW_EXCEPTION(bad_parameter, @@ -61,6 +64,8 @@ namespace hpx { namespace util on_start_thread_(on_start_thread), on_stop_thread_(on_stop_thread), pool_name_(pool_name), pool_name_postfix_(name_postfix) { + LPROGRESS_ << pool_name; + for (std::size_t i = 0; i < pool_size_; ++i) { io_services_.emplace_back(new boost::asio::io_service); diff --git a/src/util/logging.cpp b/src/util/logging.cpp index aa13addabe03..da08e7f1cb91 100644 --- a/src/util/logging.cpp +++ b/src/util/logging.cpp @@ -1,4 +1,4 @@ -// Copyright (c) 2007-2012 Hartmut Kaiser +// Copyright (c) 2007-2017 Hartmut Kaiser // Copyright (c) 2011 Bryce Lelbach // // Distributed under the Boost Software License, Version 1.0. (See accompanying @@ -176,7 +176,6 @@ namespace hpx { namespace util void operator()(param str) const { - std::uint32_t locality_id = hpx::get_locality_id(); if (naming::invalid_locality_id != locality_id) { @@ -1076,8 +1075,8 @@ namespace hpx { namespace util { namespace detail "destination = ${HPX_LOGDESTINATION:console}", "format = ${HPX_LOGFORMAT:" "(T%locality%/%hpxthread%.%hpxphase%/%hpxcomponent%) " - "P%parentloc%/%hpxparent%.%hpxparentphase% %time%(" HPX_TIMEFORMAT - ") [%idx%]|\\n}", + "P%parentloc%/%hpxparent%.%hpxparentphase% %time%(" + HPX_TIMEFORMAT ") [%idx%]|\\n}", // general console logging "[hpx.logging.console]", @@ -1085,8 +1084,8 @@ namespace hpx { namespace util { namespace detail #if defined(ANDROID) || defined(__ANDROID__) "destination = ${HPX_CONSOLE_LOGDESTINATION:android_log}", #else - "destination = ${HPX_CONSOLE_LOGDESTINATION:\ - file(hpx.$[system.pid].log)}", + "destination = ${HPX_CONSOLE_LOGDESTINATION:" + "file(hpx.$[system.pid].log)}", #endif "format = ${HPX_CONSOLE_LOGFORMAT:|}", @@ -1096,8 +1095,8 @@ namespace hpx { namespace util { namespace detail "destination = ${HPX_TIMING_LOGDESTINATION:console}", "format = ${HPX_TIMING_LOGFORMAT:" "(T%locality%/%hpxthread%.%hpxphase%/%hpxcomponent%) " - "P%parentloc%/%hpxparent%.%hpxparentphase% %time%(" HPX_TIMEFORMAT - ") [%idx%] [TIM] |\\n}", + "P%parentloc%/%hpxparent%.%hpxparentphase% %time%(" + HPX_TIMEFORMAT ") [%idx%] [TIM] |\\n}", // console logging related to timing "[hpx.logging.console.timing]", @@ -1105,8 +1104,8 @@ namespace hpx { namespace util { namespace detail #if defined(ANDROID) || defined(__ANDROID__) "destination = ${HPX_CONSOLE_TIMING_LOGDESTINATION:android_log}", #else - "destination = \ - ${HPX_CONSOLE_TIMING_LOGDESTINATION:file(hpx.timing.$[system.pid].log)}", + "destination = ${HPX_CONSOLE_TIMING_LOGDESTINATION:" + "file(hpx.timing.$[system.pid].log)}", #endif "format = ${HPX_CONSOLE_TIMING_LOGFORMAT:|}", @@ -1114,12 +1113,12 @@ namespace hpx { namespace util { namespace detail "[hpx.logging.agas]", "level = ${HPX_AGAS_LOGLEVEL:-1}", // "destination = ${HPX_AGAS_LOGDESTINATION:console}", - "destination = \ - ${HPX_AGAS_LOGDESTINATION:file(hpx.agas.$[system.pid].log)}", + "destination = ${HPX_AGAS_LOGDESTINATION:" + "file(hpx.agas.$[system.pid].log)}", "format = ${HPX_AGAS_LOGFORMAT:" "(T%locality%/%hpxthread%.%hpxphase%/%hpxcomponent%) " - "P%parentloc%/%hpxparent%.%hpxparentphase% %time%(" HPX_TIMEFORMAT - ") [%idx%][AGAS] |\\n}", + "P%parentloc%/%hpxparent%.%hpxparentphase% %time%(" + HPX_TIMEFORMAT ") [%idx%][AGAS] |\\n}", // console logging related to AGAS "[hpx.logging.console.agas]", @@ -1127,20 +1126,20 @@ namespace hpx { namespace util { namespace detail #if defined(ANDROID) || defined(__ANDROID__) "destination = ${HPX_CONSOLE_AGAS_LOGDESTINATION:android_log}", #else - "destination = ${HPX_CONSOLE_AGAS_LOGDESTINATION:file\ - (hpx.agas.$[system.pid].log)}", + "destination = ${HPX_CONSOLE_AGAS_LOGDESTINATION:" + "file(hpx.agas.$[system.pid].log)}", #endif "format = ${HPX_CONSOLE_AGAS_LOGFORMAT:|}", // logging related to the parcel transport "[hpx.logging.parcel]", "level = ${HPX_PARCEL_LOGLEVEL:-1}", - "destination = ${HPX_PARCEL_LOGDESTINATION:file\ - (hpx.parcel.$[system.pid].log)}", + "destination = ${HPX_PARCEL_LOGDESTINATION:" + "file(hpx.parcel.$[system.pid].log)}", "format = ${HPX_PARCEL_LOGFORMAT:" "(T%locality%/%hpxthread%.%hpxphase%/%hpxcomponent%) " - "P%parentloc%/%hpxparent%.%hpxparentphase% %time%(" HPX_TIMEFORMAT - ") [%idx%][ PT] |\\n}", + "P%parentloc%/%hpxparent%.%hpxparentphase% %time%(" + HPX_TIMEFORMAT ") [%idx%][ PT] |\\n}", // console logging related to the parcel transport "[hpx.logging.console.parcel]", @@ -1148,8 +1147,8 @@ namespace hpx { namespace util { namespace detail #if defined(ANDROID) || defined(__ANDROID__) "destination = ${HPX_CONSOLE_PARCEL_LOGDESTINATION:android_log}", #else - "destination = ${HPX_CONSOLE_PARCEL_LOGDESTINATION:file\ - (hpx.parcel.$[system.pid].log)}", + "destination = ${HPX_CONSOLE_PARCEL_LOGDESTINATION:" + "file(hpx.parcel.$[system.pid].log)}", #endif "format = ${HPX_CONSOLE_PARCEL_LOGFORMAT:|}", @@ -1159,8 +1158,8 @@ namespace hpx { namespace util { namespace detail "destination = ${HPX_APP_LOGDESTINATION:console}", "format = ${HPX_APP_LOGFORMAT:" "(T%locality%/%hpxthread%.%hpxphase%/%hpxcomponent%) " - "P%parentloc%/%hpxparent%.%hpxparentphase% %time%(" HPX_TIMEFORMAT - ") [%idx%] [APP] |\\n}", + "P%parentloc%/%hpxparent%.%hpxparentphase% %time%(" + HPX_TIMEFORMAT ") [%idx%] [APP] |\\n}", // console logging related to applications "[hpx.logging.console.application]", @@ -1168,8 +1167,8 @@ namespace hpx { namespace util { namespace detail #if defined(ANDROID) || defined(__ANDROID__) "destination = ${HPX_CONSOLE_APP_LOGDESTINATION:android_log}", #else - "destination = ${HPX_CONSOLE_APP_LOGDESTINATION:file\ - (hpx.application.$[system.pid].log)}", + "destination = ${HPX_CONSOLE_APP_LOGDESTINATION:" + "file(hpx.application.$[system.pid].log)}", #endif "format = ${HPX_CONSOLE_APP_LOGFORMAT:|}", @@ -1179,16 +1178,16 @@ namespace hpx { namespace util { namespace detail "destination = ${HPX_DEB_LOGDESTINATION:console}", "format = ${HPX_DEB_LOGFORMAT:" "(T%locality%/%hpxthread%.%hpxphase%/%hpxcomponent%) " - "P%parentloc%/%hpxparent%.%hpxparentphase% %time%(" HPX_TIMEFORMAT - ") [%idx%] [DEB] |\\n}", + "P%parentloc%/%hpxparent%.%hpxparentphase% %time%(" + HPX_TIMEFORMAT ") [%idx%] [DEB] |\\n}", "[hpx.logging.console.debuglog]", "level = ${HPX_DEB_LOGLEVEL:$[hpx.logging.debuglog.level]}", #if defined(ANDROID) || defined(__ANDROID__) "destination = ${HPX_CONSOLE_DEB_LOGDESTINATION:android_log}", #else - "destination = ${HPX_CONSOLE_DEB_LOGDESTINATION:file\ - (hpx.debuglog.$[system.pid].log)}", + "destination = ${HPX_CONSOLE_DEB_LOGDESTINATION:" + "file(hpx.debuglog.$[system.pid].log)}", #endif "format = ${HPX_CONSOLE_DEB_LOGFORMAT:|}" }; @@ -1210,8 +1209,7 @@ namespace hpx { namespace util { namespace detail } /////////////////////////////////////////////////////////////////////////// - init_logging::init_logging(runtime_configuration& ini, bool isconsole, - naming::resolver_client& agas_client) + void init_logging(runtime_configuration& ini, bool isconsole) { // initialize normal logs init_agas_log(ini, isconsole); @@ -1236,6 +1234,7 @@ namespace hpx { namespace util { namespace detail #include #include #include +#include #include #include @@ -1243,24 +1242,21 @@ namespace hpx { namespace util { namespace detail namespace hpx { namespace util { namespace detail { - dummy_log_impl dummy_log = dummy_log_impl(); - std::vector get_logging_data() { static std::vector dummy_data; return dummy_data; } - init_logging::init_logging(runtime_configuration& ini, bool, - naming::resolver_client&) + void init_logging(runtime_configuration& ini, bool) { // warn if logging is requested - if (ini.get_entry("hpx.logging.level", "0") != "0" || - ini.get_entry("hpx.logging.timing.level", "0") != "0" || - ini.get_entry("hpx.logging.agas.level", "0") != "0" || - ini.get_entry("hpx.logging.debuglog.level", "0") != "0" || - ini.get_entry("hpx.logging.application.level", "0") != "0") + if (util::get_entry_as(ini, "hpx.logging.level", -1) > 0 || + util::get_entry_as(ini, "hpx.logging.timing.level", -1) > 0 || + util::get_entry_as(ini, "hpx.logging.agas.level", -1) > 0 || + util::get_entry_as(ini, "hpx.logging.debuglog.level", -1) > 0 || + util::get_entry_as(ini, "hpx.logging.application.level", -1) > 0) { std::cerr << "hpx::init_logging: warning: logging is requested even " "while it was disabled at compile time. If you " diff --git a/src/util/parse_command_line.cpp b/src/util/parse_command_line.cpp index c06587441fa4..5e8a3926b4d4 100644 --- a/src/util/parse_command_line.cpp +++ b/src/util/parse_command_line.cpp @@ -60,7 +60,8 @@ namespace hpx { namespace util if (p == std::string::npos) return false; - if (hpx::util::safe_lexical_cast(s.substr(hpx_prefix_len, p-hpx_prefix_len), + if (hpx::util::safe_lexical_cast( + s.substr(hpx_prefix_len, p-hpx_prefix_len), std::size_t(-1)) == node) { // this option is for the current locality only @@ -500,6 +501,9 @@ namespace hpx { namespace util ("hpx:debug-parcel-log", value()->implicit_value("cout"), "enable all messages on the parcel transport log channel and send all " "parcel transport logs to the target destination") + ("hpx:debug-timing-log", value()->implicit_value("cout"), + "enable all messages on the timing log channel and send all " + "timing logs to the target destination") // enable debug output from command line handling ("hpx:debug-clp", "debug command line processing") #if defined(_POSIX_VERSION) || defined(HPX_WINDOWS)