diff --git a/src/hotspot/os/aix/vitals_aix.cpp b/src/hotspot/os/aix/vitals_aix.cpp index 450293ea1957..42a574fb4c19 100644 --- a/src/hotspot/os/aix/vitals_aix.cpp +++ b/src/hotspot/os/aix/vitals_aix.cpp @@ -30,11 +30,17 @@ namespace sapmachine_vitals { +static Column* g_col_system_load_average = nullptr; + bool platform_columns_initialize() { + g_col_system_load_average = + define_column("system", nullptr, "la", "Load average in the sample interval in percent", true); + return true; } -void sample_platform_values(Sample* record) { +void sample_platform_values(Sample* sample, Sample* long_term_sample) { + set_load_average(g_col_system_load_average, get_load_avg_from_os_interface(), sample, long_term_sample); } } // namespace sapmachine_vitals diff --git a/src/hotspot/os/bsd/vitals_bsd.cpp b/src/hotspot/os/bsd/vitals_bsd.cpp index 450293ea1957..42a574fb4c19 100644 --- a/src/hotspot/os/bsd/vitals_bsd.cpp +++ b/src/hotspot/os/bsd/vitals_bsd.cpp @@ -30,11 +30,17 @@ namespace sapmachine_vitals { +static Column* g_col_system_load_average = nullptr; + bool platform_columns_initialize() { + g_col_system_load_average = + define_column("system", nullptr, "la", "Load average in the sample interval in percent", true); + return true; } -void sample_platform_values(Sample* record) { +void sample_platform_values(Sample* sample, Sample* long_term_sample) { + set_load_average(g_col_system_load_average, get_load_avg_from_os_interface(), sample, long_term_sample); } } // namespace sapmachine_vitals diff --git a/src/hotspot/os/linux/vitals_linux.cpp b/src/hotspot/os/linux/vitals_linux.cpp index bb0c5b318770..cac80e221a98 100644 --- a/src/hotspot/os/linux/vitals_linux.cpp +++ b/src/hotspot/os/linux/vitals_linux.cpp @@ -105,6 +105,7 @@ static Column* g_col_system_num_threads = nullptr; static Column* g_col_system_num_procs_running = nullptr; static Column* g_col_system_num_procs_blocked = nullptr; +static Column* g_col_system_load_average = nullptr; static bool g_show_cgroup_info = false; static Column* g_col_system_cgrp_limit_in_bytes = nullptr; @@ -179,6 +180,8 @@ bool platform_columns_initialize() { define_column(system_cat, nullptr, "tr", "Number of threads running", true); g_col_system_num_procs_blocked = define_column(system_cat, nullptr, "tb", "Number of threads blocked on disk IO", true); + g_col_system_load_average = + define_column(system_cat, nullptr, "la", "Load average in the sample interval in percent", true); g_col_system_cpu_user = define_column(system_cat, "cpu", "us", "CPU user time [host]", true); @@ -261,7 +264,7 @@ static void set_value_in_sample(Column* col, Sample* sample, value_t val) { } } -void sample_platform_values(Sample* sample) { +void sample_platform_values(Sample* sample, Sample* long_term_sample) { int idx = 0; @@ -286,6 +289,7 @@ void sample_platform_values(Sample* sample) { set_value_in_sample(g_col_system_num_procs_running, sample, OSWrapper::syst_tr()); set_value_in_sample(g_col_system_num_procs_blocked, sample, OSWrapper::syst_tb()); + set_load_average(g_col_system_load_average, OSWrapper::syst_load_average(), sample, long_term_sample); // cgroups business if (g_show_cgroup_info) { diff --git a/src/hotspot/os/linux/vitals_linux_oswrapper.cpp b/src/hotspot/os/linux/vitals_linux_oswrapper.cpp index a3d997dd6a45..9a306ad04b89 100644 --- a/src/hotspot/os/linux/vitals_linux_oswrapper.cpp +++ b/src/hotspot/os/linux/vitals_linux_oswrapper.cpp @@ -27,6 +27,7 @@ #include "logging/log.hpp" #include "osContainer_linux.hpp" #include "runtime/os.hpp" +#include "runtime/timerTrace.hpp" #include "utilities/globalDefinitions.hpp" #include "vitals/vitals_internals.hpp" #include "vitals_linux_oswrapper.hpp" @@ -58,6 +59,7 @@ static const int num_seconds_until_update = 1; class ProcFile { char* _buf; + const char* _filename; // To keep the code simple, I just use a fixed sized buffer. enum { bufsize = 64*K }; @@ -66,6 +68,7 @@ class ProcFile { ProcFile() : _buf(nullptr) { _buf = (char*)os::malloc(bufsize, mtInternal); + _filename = ""; } ~ProcFile () { @@ -84,6 +87,8 @@ class ProcFile { _buf[bytes_read] = '\0'; ::fclose(f); + // All filenames we get are live for the time we need it. No need to strdup. + _filename = filename; return bytes_read > 0 && bytes_read < bufsize; } @@ -91,13 +96,13 @@ class ProcFile { const char* text() const { return _buf; } // Utility function; parse a number string as value_t - static value_t as_value(const char* text, size_t scale = 1) { + static value_t as_value(const char* prefix, const char* text, size_t scale = 1) { value_t value; errno = 0; char* endptr = nullptr; value = (value_t)::strtoll(text, &endptr, 10); if (endptr == text || errno != 0) { - log_debug(vitals, os)("Failed to parse \"%s\"", text); + log_debug(vitals, os)("Failed to parse %s: \"%s\"", prefix, text); value = INVALID_VALUE; } else { value *= scale; @@ -108,7 +113,7 @@ class ProcFile { // Return the start of the file, as number. Useful for proc files which // contain a single number. Returns INVALID_VALUE if value did not parse value_t as_value(size_t scale = 1) const { - return as_value(_buf, scale); + return as_value(_filename, _buf, scale); } const char* get_prefixed_line(const char* prefix) const { @@ -121,7 +126,7 @@ class ProcFile { if (s != nullptr) { errno = 0; const char* p = s + ::strlen(prefix); - value = as_value(p, scale); + value = as_value(prefix, p, scale); log_trace(vitals, os)("Reading \"%s\": %llu", prefix, (unsigned long long) value); } else { log_debug(vitals, os)("Could not find prefix \"%s\"", prefix); @@ -491,6 +496,7 @@ ALL_VALUES_DO(RESETVAL) // Number of processes: iterate over /proc/ and count. // Number of threads: read "num_threads" from /proc//stat { + TraceTime timer("Iterating all processes", TRACETIME_LOG(Debug, vitals, os)); DIR* d = ::opendir("/proc"); if (d != nullptr) { value_t v_p = 0; @@ -556,6 +562,14 @@ ALL_VALUES_DO(RESETVAL) } #endif // __GLIBC__ + if ((VitalsSampleInterval < 30) && (_syst_tr != INVALID_VALUE)) { + // For short sample times we use the number of runnable and running threads + // to approximate the load average in that interval. + _syst_load_average = (value_t) MAX2(0.0, _syst_tr * get_proc_scale_factor()); + } else { + _syst_load_average = get_load_avg_from_os_interface(); + } + first_call = false; } diff --git a/src/hotspot/os/linux/vitals_linux_oswrapper.hpp b/src/hotspot/os/linux/vitals_linux_oswrapper.hpp index f58813dda0e5..c56ee07e4f99 100644 --- a/src/hotspot/os/linux/vitals_linux_oswrapper.hpp +++ b/src/hotspot/os/linux/vitals_linux_oswrapper.hpp @@ -48,6 +48,7 @@ class OSWrapper { f(syst_t) \ f(syst_tr) \ f(syst_tb) \ + f(syst_load_average) \ f(syst_cpu_us) \ f(syst_cpu_sy) \ f(syst_cpu_id) \ diff --git a/src/hotspot/os/windows/vitals_windows.cpp b/src/hotspot/os/windows/vitals_windows.cpp index bb1e9812f161..fb2c0d103e7c 100644 --- a/src/hotspot/os/windows/vitals_windows.cpp +++ b/src/hotspot/os/windows/vitals_windows.cpp @@ -23,27 +23,131 @@ * */ +#include "logging/log.hpp" #include "runtime/os.hpp" +#include "runtime/timerTrace.hpp" #include "utilities/debug.hpp" #include "utilities/globalDefinitions.hpp" +#include "utilities/ostream.hpp" #include "vitals/vitals_internals.hpp" +#include "pdh_interface.hpp" #include namespace sapmachine_vitals { +static const DWORD PDH_SYSTEM_IDX = 2; +static const DWORD PDH_PROCESSOR_TIME_IDX = 6; +static const DWORD PDH_PROCESSOR_QUEUE_LENGTH_IDX = 44; +static const DWORD PDH_PROCESSOR_IDX = 238; + static Column* g_col_system_memoryload = nullptr; static Column* g_col_system_avail_phys = nullptr; +static Column* g_col_system_load_average = nullptr; static Column* g_col_process_working_set_size = nullptr; static Column* g_col_process_commit_charge = nullptr; +static bool log_pdh(const char* operation, PDH_STATUS status) { + if (status != ERROR_SUCCESS) { + log_debug(vitals)("pdh operation '%s' failed with error code %x", operation, status); + return false; + } + + return true; +} + +static bool has_loadavg = false; +static double proc_scale_factor = 1.0; + +static HQUERY query; +static HCOUNTER queue_length_counter, processor_time_counter; +static PDH_FMT_COUNTERVALUE queue_length, processor_time; + +static bool add_pdh_string_from_index(DWORD index, stringStream* ss) { + DWORD size = 0; + + if (PdhDll::PdhLookupPerfNameByIndex(nullptr, index, nullptr, &size) != PDH_MORE_DATA) { + return false; + } + + char* pdh_string = NEW_C_HEAP_ARRAY(char, size, mtInternal); + pdh_string[size - 1] = '\0'; + PDH_STATUS status = PdhDll::PdhLookupPerfNameByIndex(nullptr, index, pdh_string, &size); + + if (status == ERROR_SUCCESS) { + ss->print_raw(pdh_string); + } else { + log_pdh("Converting index failed", status); + } + + FREE_C_HEAP_ARRAY(pdh_string); + + return status == ERROR_SUCCESS; +} + +static double get_load_average_impl(bool first_call) { + double load_avg = -1; + + if (first_call) { + stringStream queue_lengt_counter_name; + queue_lengt_counter_name.put('\\'); + bool success = add_pdh_string_from_index(PDH_SYSTEM_IDX, &queue_lengt_counter_name); + queue_lengt_counter_name.put('\\'); + success = success && add_pdh_string_from_index(PDH_PROCESSOR_QUEUE_LENGTH_IDX, &queue_lengt_counter_name); + + stringStream processor_time_counter_name; + processor_time_counter_name.put('\\'); + success = success && add_pdh_string_from_index(PDH_PROCESSOR_IDX, &processor_time_counter_name); + processor_time_counter_name.print_raw("(_Total)\\"); + success = success && add_pdh_string_from_index(PDH_PROCESSOR_TIME_IDX, &processor_time_counter_name); + + if (!success) { + log_debug(vitals)("Could not create the localized counters: '%s', '%s'", queue_lengt_counter_name.base(), processor_time_counter_name.base()); + return load_avg; + } + + has_loadavg = log_pdh("open query", PdhDll::PdhOpenQuery(nullptr, 0, &query)) && + log_pdh("add queue length", PdhDll::PdhAddCounter(query, queue_lengt_counter_name.base(), 0, &queue_length_counter)) && + log_pdh("add processor time", PdhDll::PdhAddCounter(query, processor_time_counter_name.base(), 0, &processor_time_counter)) && + log_pdh("collect data", PdhDll::PdhCollectQueryData(query)); + proc_scale_factor = 100.0 / MAX2(1, os::processor_count()); + } + else { + TraceTime timer("Getting the counter values", TRACETIME_LOG(Debug, vitals, os)); + + if (log_pdh("collect data", PdhDll::PdhCollectQueryData(query)) && + log_pdh("format queue length", PdhDll::PdhGetFormattedCounterValue(queue_length_counter, PDH_FMT_DOUBLE, nullptr, &queue_length)) && + log_pdh("format processor time", PdhDll::PdhGetFormattedCounterValue(processor_time_counter, PDH_FMT_DOUBLE, nullptr, &processor_time))) { + log_debug(vitals)("Queue length %d, processor time %d", (int)queue_length.doubleValue, (int)processor_time.doubleValue); + load_avg = processor_time.doubleValue + queue_length.doubleValue * proc_scale_factor; + } + } + + return load_avg; +} + +static void initialize_pdh() { + if (!PdhDll::PdhAttach()) { + log_debug(vitals)("Could not attach pdh lib."); + return; + } + + get_load_average_impl(true); +} + bool platform_columns_initialize() { + initialize_pdh(); + g_col_system_memoryload = define_column("system", nullptr, "mload", "Approximate percentage of physical memory that is in use.", true, MAX); // MEMORYSTATUSEX ullAvailPhys g_col_system_avail_phys = define_column("system", nullptr, "avail-phys", "Amount of physical memory currently available.", true, MIN); + + g_col_system_load_average = + define_column("system", nullptr, "la", "Load average in the sample interval in percent.", has_loadavg, MAX); + // PROCESS_MEMORY_COUNTERS_EX WorkingSetSize g_col_process_working_set_size = define_column("system", nullptr, "wset", "Working set size", true); @@ -62,7 +166,15 @@ static void set_value_in_sample(Column* col, Sample* sample, value_t val) { } } -void sample_platform_values(Sample* sample) { +static value_t get_load_average() { + if (!has_loadavg) { + return INVALID_VALUE; + } + + return get_load_average_impl(false); +} + +void sample_platform_values(Sample* sample, Sample* long_term_sample) { MEMORYSTATUSEX mse; mse.dwLength = sizeof(mse); if (::GlobalMemoryStatusEx(&mse)) { @@ -76,6 +188,8 @@ void sample_platform_values(Sample* sample) { set_value_in_sample(g_col_process_working_set_size, sample, cnt.WorkingSetSize); set_value_in_sample(g_col_process_commit_charge, sample, cnt.PagefileUsage); } + + set_load_average(g_col_system_load_average, get_load_average(), sample, long_term_sample); } } // namespace sapmachine_vitals diff --git a/src/hotspot/share/runtime/threads.cpp b/src/hotspot/share/runtime/threads.cpp index 37007a9b4f97..55eb1d3a7a2f 100644 --- a/src/hotspot/share/runtime/threads.cpp +++ b/src/hotspot/share/runtime/threads.cpp @@ -859,6 +859,9 @@ jint Threads::create_vm(JavaVMInitArgs* args, bool* canTryAgain) { sapmachine_vitals::initialize_himem_report_facility(); } #endif // LINUX + if (EnableVitals) { + sapmachine_vitals::begin_sampling(); + } #if INCLUDE_MANAGEMENT bool start_agent = true; diff --git a/src/hotspot/share/vitals/vitals.cpp b/src/hotspot/share/vitals/vitals.cpp index b326b5338eca..3d1dea4399bb 100644 --- a/src/hotspot/share/vitals/vitals.cpp +++ b/src/hotspot/share/vitals/vitals.cpp @@ -831,8 +831,14 @@ class SampleTables: public CHeapObj { _large_table_count(MAX2(1, (int) (VitalsLongTermSampleIntervalMinutes * 60 / VitalsSampleInterval))) {} - void add_sample(const Sample* sample) { + // Should the next sample call include long term values. + bool next_sample_is_for_long_term() { + return ((_count + 1) % _large_table_count) == 0; + } + + void add_sample(const Sample* sample, Sample* long_term_sample) { AutoLock autolock(&g_vitals_lock); + // Nothing we do in here blocks: the sample values are already taken, // we only modify existing data structures (no memory is allocated either). _short_term_table.add_sample(sample); @@ -841,7 +847,8 @@ class SampleTables: public CHeapObj { _count++; // Feed long term table if ((_count % _large_table_count) == 0) { - _long_term_table.add_sample(sample); + assert(long_term_sample != nullptr, "should have the long term sample"); + _long_term_table.add_sample(long_term_sample); } // Update exetremum samples if needed. @@ -962,18 +969,24 @@ static SampleTables* g_all_tables = nullptr; /////////////// SAMPLING ////////////////////// // Samples all values, but leaves timestamp unchanged -static void sample_values(Sample* sample, bool avoid_locking) { +static void sample_values(Sample* sample, Sample* long_term_sample, bool avoid_locking) { time_t t; ::time(&t); sample->set_timestamp(t); + + if (long_term_sample != nullptr) { + long_term_sample->set_timestamp(t); + } + DEBUG_ONLY(sample->set_num(-1);) sample_jvm_values(sample, avoid_locking); - sample_platform_values(sample); + sample_platform_values(sample, long_term_sample); } class SamplerThread: public NamedThread { Sample* _sample; + Sample* _long_term_sample; bool _stop; int _samples_taken; int _jump_cooldown; @@ -982,12 +995,27 @@ class SamplerThread: public NamedThread { return (int)VitalsSampleInterval * 1000; } - void take_sample() { + void take_sample(bool for_long_term) { _sample->reset(); + + if (for_long_term) { + _long_term_sample->reset(); + } + DEBUG_ONLY(_sample->set_num(_samples_taken);) _samples_taken ++; - sample_values(_sample, VitalsLockFreeSampling); - g_all_tables->add_sample(_sample); + sample_values(_sample, for_long_term ? _long_term_sample : nullptr, VitalsLockFreeSampling); + + // Fill in missing values in the long term table from the short term table. + if (for_long_term) { + for (int i = 0; i < _long_term_sample->num_values(); ++i) { + if (_long_term_sample->value(i) == INVALID_VALUE) { + _long_term_sample->set_value(i, _sample->value(i)); + } + } + } + + g_all_tables->add_sample(_sample, for_long_term ? _long_term_sample : nullptr); } public: @@ -1000,13 +1028,14 @@ class SamplerThread: public NamedThread { _jump_cooldown(0) { _sample = Sample::allocate(); + _long_term_sample = Sample::allocate(); this->set_name("vitals sampler thread"); } virtual void run() { record_stack_base_and_size(); for (;;) { - take_sample(); + take_sample(g_all_tables->next_sample_is_for_long_term()); os::naked_sleep(get_sample_interval_ms()); if (_stop) { break; @@ -1321,7 +1350,7 @@ bool initialize() { g_all_tables = new SampleTables(); success = success && (g_all_tables != nullptr); - success = success && initialize_sampler_thread(); + success = success && initialize_load_average(); if (success) { log_info(vitals)("Vitals initialized."); @@ -1334,6 +1363,18 @@ bool initialize() { } +bool begin_sampling() { + bool success = initialize_sampler_thread(); + + if (success) { + log_debug(vitals)("Sampler thread started."); + } else { + log_debug(vitals)("Sampler thread failed to start."); + } + + return success; +} + void cleanup() { if (g_sampler_thread != nullptr) { g_sampler_thread->stop(); @@ -1389,7 +1430,7 @@ void print_report(outputStream* st, const print_info_t* pinfo) { Sample* sample_now = nullptr; if (info.sample_now && !info.csv) { sample_now = Sample::allocate(); - sample_values(sample_now, true /* never lock for now sample - be safe */ ); + sample_values(sample_now, nullptr, true /* never lock for now sample - be safe */ ); } g_all_tables->print_all(st, &info, sample_now); @@ -1449,4 +1490,87 @@ void dump_reports() { // For printing in thread lists only. const Thread* samplerthread() { return g_sampler_thread; } +// Load average handling. +static float* load_avg_hist = nullptr; +static int load_avg_hist_size = 0; +static int load_avg_hist_next_pos = 0; +static double proc_scale_factor = 0.0; + +bool initialize_load_average() { + load_avg_hist_size = (int)(1 + VitalsLongTermSampleIntervalMinutes * 60 / MAX2((uintx)1, VitalsSampleInterval)); + load_avg_hist = NEW_C_HEAP_ARRAY(float, load_avg_hist_size, mtInternal); + proc_scale_factor = 100.0 / MAX2(1, os::processor_count()); + + for (int i = 0; i < load_avg_hist_size; ++i) { + load_avg_hist[i] = -1.0; + } + + return true; +} + +double get_proc_scale_factor() { + return proc_scale_factor; +} + +void add_load_average(value_t load_avg) { + load_avg_hist[load_avg_hist_next_pos] = load_avg == INVALID_VALUE ? -1.0f : (float) load_avg; + load_avg_hist_next_pos = (load_avg_hist_next_pos + 1) % load_avg_hist_size; +} + +value_t get_long_term_load_average() { + double history_average = 0.0; + int nr_of_history_entries = 0; + + for (int i = 0; i < load_avg_hist_size; ++i) { + if (load_avg_hist[i] >= 0.0) { + history_average += load_avg_hist[i]; + nr_of_history_entries++; + } + } + + return nr_of_history_entries == 0 ? INVALID_VALUE : (value_t) (history_average / MAX2(1, nr_of_history_entries)); +} + +value_t get_load_avg_from_os_interface() { +#ifndef _WINDOWS + double avgs[3]; + int nr_of_avgs = os::loadavg(avgs, 3); + value_t load_avg; + + if (nr_of_avgs >= 1) { + // Convert to relative percentage-based loads, where 100 percent + // means the number of runnable threads equals the number of CPUs. + // And use the load average value most representative for the interval + if ((VitalsSampleInterval < 150) || (nr_of_avgs < 2)) { + load_avg = (value_t) MAX2(0.0, avgs[0] * proc_scale_factor); + } else if ((VitalsSampleInterval < 450) || (nr_of_avgs < 3)) { + load_avg = (value_t) MAX2(0.0, avgs[1] * proc_scale_factor); + } else { + load_avg = (value_t) MAX2(0.0, avgs[2] * proc_scale_factor); + } + } else { + load_avg = INVALID_VALUE; + static bool traced = false; + + if (!traced) { + log_trace(vitals)("Could not get load average"); + traced = true; + } + } + + return load_avg; +#else + return INVALID_VALUE; +#endif +} + +void set_load_average(Column* column, value_t load_avg, Sample* sample, Sample* long_term_sample) { + add_load_average(load_avg); + set_value_in_sample(column, sample, load_avg); + + if (long_term_sample != nullptr) { + set_value_in_sample(column, long_term_sample, get_long_term_load_average()); + } +} + } // namespace sapmachine_vitals diff --git a/src/hotspot/share/vitals/vitals.hpp b/src/hotspot/share/vitals/vitals.hpp index b09c45967c4a..b604f7b114d4 100644 --- a/src/hotspot/share/vitals/vitals.hpp +++ b/src/hotspot/share/vitals/vitals.hpp @@ -40,6 +40,7 @@ class Thread; namespace sapmachine_vitals { bool initialize(); + bool begin_sampling(); void cleanup(); struct print_info_t { diff --git a/src/hotspot/share/vitals/vitals_internals.hpp b/src/hotspot/share/vitals/vitals_internals.hpp index 4314318575d3..2f6adf4cf22b 100644 --- a/src/hotspot/share/vitals/vitals_internals.hpp +++ b/src/hotspot/share/vitals/vitals_internals.hpp @@ -241,10 +241,16 @@ namespace sapmachine_vitals { return c; } + // Load average handling. + bool initialize_load_average(); + double get_proc_scale_factor(); + value_t get_load_avg_from_os_interface(); + void set_load_average(Column* column, value_t load_avg, Sample* sample, Sample* long_term_sample); + // Ask platform to add platform specific columns bool platform_columns_initialize(); - void sample_platform_values(Sample* sample); + void sample_platform_values(Sample* sample, Sample* long_term_sample); void sample_jvm_values(Sample* sample, bool avoid_locking); }; // namespace sapmachine_vitals