add size as diagnose info when easy cost more than 10ms in socket read/write or allocate memory

This commit is contained in:
obdev 2023-04-18 09:11:42 +00:00 committed by ob-robot
parent d4496f11cf
commit e392fc2a37
4 changed files with 34 additions and 7 deletions

View File

@ -153,6 +153,19 @@ void __tg_stat_cleanup(void *s)
}
}
void __tg_stat_cleanup_s(void *s)
{
int64_t cost = get_us() - ((struct easy_stat_time_guard_t *)s)->start;
int64_t *cnt = ((struct easy_stat_time_guard_t *)s)->cnt;
*cnt += 1;
int64_t *time = ((struct easy_stat_time_guard_t *)s)->time;
*time += cost;
if (cost > ev_loop_warn_threshold) {
easy_warn_log("easy cost too much time: %ldus, procedure: %s, size:%u", cost, ((struct easy_stat_time_guard_t *)s)->procedure,
*(((struct easy_stat_time_guard_t *)s)->size));
}
}
void __tg_io_cleanup(void *s)
{
int ret = 0;
@ -165,14 +178,16 @@ void __tg_io_cleanup(void *s)
if (cost > ev_loop_warn_threshold) {
ret = getloadavg(loadavg, 3);
if (ret == 3) {
easy_warn_log("easy cost too much time(%ldus). loadavg(%lf, %lf, %lf), procedure: %s",
easy_warn_log("easy cost too much time(%ldus). loadavg(%lf, %lf, %lf), procedure: %s, size:%u",
cost,
loadavg[0],
loadavg[1],
loadavg[2],
((struct easy_stat_time_guard_t *)s)->procedure);
((struct easy_stat_time_guard_t *)s)->procedure,
*(((struct easy_stat_time_guard_t *)s)->size));
} else {
easy_warn_log("easy cost too much time(%ldus), procedure: %s", cost, ((struct easy_stat_time_guard_t *)s)->procedure);
easy_warn_log("easy cost too much time(%ldus), procedure: %s, size:%u", cost, ((struct easy_stat_time_guard_t *)s)->procedure,
*(((struct easy_stat_time_guard_t *)s)->size));
}
}
}

View File

@ -78,6 +78,7 @@ uint64_t easy_fnv_hash(const char *str);
void __tg_cleanup(void *s);
void __tg_stat_cleanup(void *s);
void __tg_io_cleanup(void *s);
void __tg_stat_cleanup_s(void *s);
extern int64_t ev_loop_warn_threshold;
extern __thread int64_t ev_malloc_count;
@ -98,6 +99,7 @@ struct easy_stat_time_guard_t {
int64_t *cnt;
int64_t *time;
const char *procedure;
uint32_t *size;
};
struct easy_time_guard_t {
@ -113,18 +115,28 @@ struct easy_time_guard_t {
.procedure = __FUNCTION__, \
};
#define EASY_STAT_TIME_GUARD_WITH_SIZE(_cnt, _time, _size) \
struct easy_stat_time_guard_t _tg_stat_time_guard __attribute__((cleanup(__tg_stat_cleanup_s))) = { \
.start = get_us(), \
.cnt = &(_cnt), \
.time = &(_time), \
.procedure = __FUNCTION__, \
.size = (uint32_t *)&(_size), \
};
#define EASY_TIME_GUARD() \
struct easy_time_guard_t _tg_time_guard __attribute__((cleanup(__tg_cleanup))) = { \
.start = get_us(), \
.procedure = __FUNCTION__, \
};
#define EASY_SOCKET_IO_TIME_GUARD(_cnt, _time) \
#define EASY_SOCKET_IO_TIME_GUARD(_cnt, _time, _size) \
struct easy_stat_time_guard_t _tg__io_time_guard __attribute__((cleanup(__tg_io_cleanup))) = { \
.start = get_us(), \
.cnt = &(_cnt), \
.time = &(_time), \
.procedure = __FUNCTION__, \
.size = (uint32_t *)&(_size), \
};
EASY_CPP_END

View File

@ -196,7 +196,7 @@ char* easy_socket_err_reason(int error_no)
ssize_t easy_socket_read(easy_connection_t *conn, char *buf, size_t size, int *pending)
{
ssize_t n;
EASY_SOCKET_IO_TIME_GUARD(ev_read_count, ev_read_time);
EASY_SOCKET_IO_TIME_GUARD(ev_read_count, ev_read_time, size);
do {
n = recv(conn->fd, buf, size, 0);
@ -236,7 +236,7 @@ ssize_t easy_socket_tcpwrite(easy_connection_t *conn, easy_list_t *l)
ssize_t sended, size, wbyte, ret;
int cnt, again;
EASY_SOCKET_IO_TIME_GUARD(ev_write_count, ev_write_time);
EASY_SOCKET_IO_TIME_GUARD(ev_write_count, ev_write_time, wbyte);
wbyte = cnt = sended = again = 0;
// foreach

View File

@ -93,7 +93,7 @@ void easy_pool_destroy(easy_pool_t *pool)
void *easy_pool_alloc_ex(easy_pool_t *pool, uint32_t size, int align)
{
EASY_STAT_TIME_GUARD(ev_malloc_count, ev_malloc_time);
EASY_STAT_TIME_GUARD_WITH_SIZE(ev_malloc_count, ev_malloc_time, size);
uint8_t *m;
easy_pool_t *p;
int dsize;