Skip to content
Browse files

track calls to recv, measure gc stime/utime, fix truncation of time_ms

  • Loading branch information...
1 parent 47d6d1d commit 8a7623b8e2a98955c701d483741494f8c69bcf1d @tmm1 tmm1 committed
Showing with 61 additions and 9 deletions.
  1. +42 −5 ext/tracers/fd.c
  2. +16 −1 ext/tracers/gc.c
  3. +1 −1 ext/tracers/mysql.c
  4. +0 −2 ext/tracers/resources.c
  5. +2 −0 ext/util.h
View
47 ext/tracers/fd.c
@@ -27,6 +27,10 @@ struct memprof_fd_stats {
size_t write_requested_bytes;
size_t write_actual_bytes;
+ size_t recv_calls;
+ uint32_t recv_time;
+ ssize_t recv_actual_bytes;
+
size_t connect_calls;
uint32_t connect_time;
@@ -42,7 +46,7 @@ static struct memprof_fd_stats stats;
static ssize_t
read_tramp(int fildes, void *buf, size_t nbyte) {
- uint32_t millis = 0;
+ uint64_t millis = 0;
int err;
ssize_t ret;
@@ -63,7 +67,7 @@ read_tramp(int fildes, void *buf, size_t nbyte) {
static ssize_t
write_tramp(int fildes, const void *buf, size_t nbyte) {
- uint32_t millis = 0;
+ uint64_t millis = 0;
int err;
ssize_t ret;
@@ -82,9 +86,29 @@ write_tramp(int fildes, const void *buf, size_t nbyte) {
return ret;
}
+static ssize_t
+recv_tramp(int socket, void *buffer, size_t length, int flags) {
+ uint64_t millis = 0;
+ int err;
+ ssize_t ret;
+
+ millis = timeofday_ms();
+ ret = recv(socket, buffer, length, flags);
+ err = errno;
+ millis = timeofday_ms() - millis;
+
+ stats.recv_time += millis;
+ stats.recv_calls++;
+ if (ret > 0)
+ stats.recv_actual_bytes += ret;
+
+ errno = err;
+ return ret;
+}
+
static int
connect_tramp(int socket, const struct sockaddr *address, socklen_t address_len) {
- uint32_t millis = 0;
+ uint64_t millis = 0;
int err, ret;
millis = timeofday_ms();
@@ -102,7 +126,7 @@ connect_tramp(int socket, const struct sockaddr *address, socklen_t address_len)
static int
select_tramp(int nfds, fd_set *readfds, fd_set *writefds, fd_set *errorfds, struct timeval *timeout)
{
- uint32_t millis = 0;
+ uint64_t millis = 0;
int ret, err;
millis = timeofday_ms();
@@ -120,7 +144,7 @@ select_tramp(int nfds, fd_set *readfds, fd_set *writefds, fd_set *errorfds, stru
static int
poll_tramp(struct pollfd fds[], nfds_t nfds, int timeout)
{
- uint32_t millis = 0;
+ uint64_t millis = 0;
int ret, err;
millis = timeofday_ms();
@@ -153,6 +177,7 @@ fd_trace_start() {
#else
insert_tramp("select", select_tramp);
insert_tramp("connect", connect_tramp);
+ insert_tramp("recv", recv_tramp);
#endif
}
@@ -195,6 +220,18 @@ fd_trace_dump(json_gen gen) {
json_gen_map_close(gen);
}
+ if (stats.recv_calls > 0) {
+ json_gen_cstr(gen, "recv");
+ json_gen_map_open(gen);
+ json_gen_cstr(gen, "calls");
+ json_gen_integer(gen, stats.recv_calls);
+ json_gen_cstr(gen, "time");
+ json_gen_integer(gen, stats.recv_time);
+ json_gen_cstr(gen, "actual");
+ json_gen_integer(gen, stats.recv_actual_bytes);
+ json_gen_map_close(gen);
+ }
+
if (stats.connect_calls > 0) {
json_gen_cstr(gen, "connect");
json_gen_map_open(gen);
View
17 ext/tracers/gc.c
@@ -3,6 +3,7 @@
#include <stdlib.h>
#include <string.h>
#include <sys/time.h>
+#include <sys/resource.h>
#include "arch.h"
#include "bin_api.h"
@@ -14,6 +15,8 @@
struct memprof_gc_stats {
size_t gc_calls;
uint32_t gc_time;
+ uint32_t gc_utime;
+ uint32_t gc_stime;
};
static struct tracer tracer;
@@ -23,14 +26,20 @@ static void (*orig_garbage_collect)();
static void
gc_tramp()
{
- uint32_t millis = 0;
+ uint64_t millis = 0;
+ struct rusage usage_start, usage_end;
millis = timeofday_ms();
+ getrusage(RUSAGE_SELF, &usage_start);
orig_garbage_collect();
+ getrusage(RUSAGE_SELF, &usage_end);
millis = timeofday_ms() - millis;
stats.gc_time += millis;
stats.gc_calls++;
+
+ stats.gc_utime += TVAL_TO_INT64(usage_end.ru_utime) - TVAL_TO_INT64(usage_start.ru_utime);
+ stats.gc_stime += TVAL_TO_INT64(usage_end.ru_stime) - TVAL_TO_INT64(usage_start.ru_stime);
}
static void
@@ -65,6 +74,12 @@ gc_trace_dump(json_gen gen) {
json_gen_cstr(gen, "time");
json_gen_integer(gen, stats.gc_time);
+
+ json_gen_cstr(gen, "utime");
+ json_gen_integer(gen, stats.gc_utime);
+
+ json_gen_cstr(gen, "stime");
+ json_gen_integer(gen, stats.gc_stime);
}
void install_gc_tracer()
View
2 ext/tracers/mysql.c
@@ -30,7 +30,7 @@ static int (*orig_send_query)(void *mysql, const char *stmt_str, unsigned long l
static int
real_query_tramp(void *mysql, const char *stmt_str, unsigned long length) {
enum memprof_sql_type type;
- uint32_t millis = 0;
+ uint64_t millis = 0;
int ret;
millis = timeofday_ms();
View
2 ext/tracers/resources.c
@@ -22,8 +22,6 @@ struct memprof_resources_stats {
static struct tracer tracer;
static struct memprof_resources_stats stats;
-#define TVAL_TO_INT64(tv) ((int64_t)tv.tv_sec*1e3 + (int64_t)tv.tv_usec*1e-3)
-
static void
resources_trace_start() {
struct rusage usage;
View
2 ext/util.h
@@ -84,4 +84,6 @@ timeofday();
*/
uint64_t
timeofday_ms();
+
+#define TVAL_TO_INT64(tv) ((int64_t)tv.tv_sec*1e3 + (int64_t)tv.tv_usec*1e-3)
#endif

0 comments on commit 8a7623b

Please sign in to comment.
Something went wrong with that request. Please try again.