diff --git a/README.md b/README.md index f6b121b0..6a5bb801 100644 --- a/README.md +++ b/README.md @@ -247,12 +247,14 @@ Emitted when a garbage collection (GC) cycle occurs in the underlying V8 runtime Emitted when all possible environment variables have been collected. Use `appmetrics.monitor.getEnvironment()` to access the available environment variables. ### Event: 'loop' -Emitted every 60 seconds, summarising event tick information in time interval +Emitted every 5 seconds, summarising event tick information in time interval * `data` (Object) the data from the event loop sample: * `count` (Number) the number of event loop ticks in the last interval. * `minimum` (Number) the shortest (i.e. fastest) tick in milliseconds. * `maximum` (Number) the longest (slowest) tick in milliseconds. * `average` (Number) the average tick time in milliseconds. + * `cpu_user` (Number) the percentage of 1 CPU used by the event loop thread in user code the last interval. This is a value between 0.0 and 1.0. + * `cpu_system` (Number) the percentage of 1 CPU used by the event loop thread in system code in the last interval. This is a value between 0.0 and 1.0. ### Event: 'memory' Emitted when a memory monitoring sample is taken. diff --git a/appmetrics-api.js b/appmetrics-api.js index abe9eb56..9c33a254 100644 --- a/appmetrics-api.js +++ b/appmetrics-api.js @@ -218,6 +218,8 @@ function API(agent, appmetrics) { maximum: parseFloat(values[2]), count: parseInt(values[3]), average: parseFloat(values[4]), + cpu_user: parseFloat(values[5]), + cpu_system: parseFloat(values[6]), }; that.emit('loop', loop); }); diff --git a/src/plugins/node/loop/nodeloopplugin.cpp b/src/plugins/node/loop/nodeloopplugin.cpp index 58d638ea..d941b2f9 100644 --- a/src/plugins/node/loop/nodeloopplugin.cpp +++ b/src/plugins/node/loop/nodeloopplugin.cpp @@ -25,6 +25,7 @@ #include #else #include +#include #endif #define DEFAULT_CAPACITY 10240 @@ -58,6 +59,40 @@ uint64_t max = 0; uint64_t num = 0; uint64_t sum = 0; +uint64_t last_cpu_user = 0; +uint64_t last_cpu_sys = 0; +uint64_t last_cpu_ts = 0; + +void getThreadCPUTime(uint64_t* cpu_user, uint64_t* cpu_sys) { + // Get the CPU time for this thread +#ifdef RUSAGE_THREAD + struct rusage stats; + if (getrusage(RUSAGE_THREAD, &stats) == 0) { +#if defined(__APPLE__) || defined(_AIX) + *cpu_user = (uint64_t)(stats.ru_utime.tv_sec * 1000) + (uint64_t)(stats.ru_utime.tv_usec / 1000); + *cpu_sys = (uint64_t)(stats.ru_stime.tv_sec * 1000) + (uint64_t)(stats.ru_stime.tv_usec / 1000); +#else + *cpu_user = (uint64_t)(stats.ru_utime.tv_sec * 1000) + (uint64_t)(stats.ru_utime.tv_usec / 1000); + *cpu_sys = (uint64_t)(stats.ru_stime.tv_sec * 1000) + (uint64_t)(stats.ru_stime.tv_usec / 1000); +#endif + } +#elif defined(__APPLE__) + mach_msg_type_number_t count = THREAD_BASIC_INFO_COUNT; + mach_port_t thread = pthread_mach_thread_np(pthread_self()); + thread_basic_info thr_info; + + kern_return_t rc = thread_info(thread, THREAD_BASIC_INFO, + (thread_info_t) &thr_info, &count); + + if (rc == KERN_SUCCESS) { + *cpu_user = (thr_info.user_time.seconds * 1000) + (thr_info.user_time.microseconds / 1000); + *cpu_sys = (thr_info.system_time.seconds * 1000) + (thr_info.system_time.microseconds / 1000); + } +#else + *cpu_user = 0; + *cpu_sys = 0; +#endif +} #if NODE_VERSION_AT_LEAST(0, 11, 0) // > v0.11+ static void GetLoopInformation(uv_timer_s *data) { @@ -65,9 +100,16 @@ static void GetLoopInformation(uv_timer_s *data) { static void GetLoopInformation(uv_timer_s *data, int status) { #endif if (num != 0) { - // Convert from nanoseconds to milliseconds. + + uint64_t cpu_user = 0; + uint64_t cpu_sys = 0; + uint64_t cpu_ts = uv_hrtime() / (1000*1000); + getThreadCPUTime(&cpu_user, &cpu_sys); + + // Convert from nanoseconds to milliseconds. double mean = (sum / 1e6) / num; + double cpu_duration = (double)(cpu_ts - last_cpu_ts); std::stringstream contentss; contentss << "NodeLoopData"; @@ -75,6 +117,8 @@ static void GetLoopInformation(uv_timer_s *data, int status) { contentss << "," << (max / 1e6); contentss << "," << num; contentss << "," << mean; + contentss << "," << (double)(((double)(cpu_user - last_cpu_user)) / cpu_duration); + contentss << "," << (double)(((double)(cpu_sys - last_cpu_sys)) / cpu_duration); contentss << '\n'; std::string content = contentss.str(); @@ -83,6 +127,9 @@ static void GetLoopInformation(uv_timer_s *data, int status) { max = 0; num = 0; sum = 0; + last_cpu_user = cpu_user; + last_cpu_sys = cpu_sys; + last_cpu_ts = cpu_ts; // Send data @@ -160,6 +207,9 @@ extern "C" { NODELOOPPLUGIN_DECL int ibmras_monitoring_plugin_start() { plugin::api.logMessage(fine, "[loop_node] Starting"); + last_cpu_ts = uv_hrtime() / (1000*1000); + getThreadCPUTime(&last_cpu_user, &last_cpu_sys); + uv_prepare_start(&prepare_handle, OnPrepare); uv_check_start(&check_handle, OnCheck); uv_timer_start(plugin::timer, GetLoopInformation, LOOP_INTERVAL, LOOP_INTERVAL);