From af8c4eabca88f6471e1ef72c2d8f44f641f6d252 Mon Sep 17 00:00:00 2001 From: "Carsten Haitzler (Rasterman)" Date: Fri, 8 May 2015 16:58:18 +0900 Subject: [PATCH] eina debug - clean up protocol handling inside eina --- src/lib/eina/eina_debug.h | 3 + src/lib/eina/eina_debug_monitor.c | 134 ++++++++++++++++++++------------------ src/lib/eina/eina_debug_proto.c | 108 +++++++++++++++++++++++++++--- 3 files changed, 171 insertions(+), 74 deletions(-) diff --git a/src/lib/eina/eina_debug.h b/src/lib/eina/eina_debug.h index f4494af..c3f82e1 100644 --- a/src/lib/eina/eina_debug.h +++ b/src/lib/eina/eina_debug.h @@ -71,7 +71,10 @@ void _eina_debug_monitor_thread_start(void); void _eina_debug_monitor_signal_init(void); void _eina_debug_monitor_service_connect(void); +int _eina_debug_monitor_service_send(int fd, const char op[4], + unsigned char *data, int size); void _eina_debug_monitor_service_greet(void); +int _eina_debug_monitor_service_read(char *op, unsigned char **data); # define EINA_BT(file) \ do { \ diff --git a/src/lib/eina/eina_debug_monitor.c b/src/lib/eina/eina_debug_monitor.c index 74833f3..fe96326 100644 --- a/src/lib/eina/eina_debug_monitor.c +++ b/src/lib/eina/eina_debug_monitor.c @@ -20,6 +20,7 @@ static int *_bt_buf_len; static struct timespec *_bt_ts; static int *_bt_cpu; +// a backtracer that uses libunwind to do the job static inline int _eina_debug_unwind_bt(void **bt, int max) { @@ -28,16 +29,24 @@ _eina_debug_unwind_bt(void **bt, int max) unw_word_t p; int total; + // create a context for unwinding unw_getcontext(&uc); + // begin our work unw_init_local(&cursor, &uc); + // walk up each stack frame until there is no more, storing it for (total = 0; (unw_step(&cursor) > 0) && (total < max); total++) { unw_get_reg(&cursor, UNW_REG_IP, &p); bt[total] = (void *)p; } + // return our total backtrace stack size return total; } +// this signal handler is called inside each and every thread when the +// thread gets a signal via pthread_kill(). this causes the thread to +// stop here inside this handler and "do something" then when this returns +// resume whatever it was doing like any signal handler static void _eina_debug_signal(int sig EINA_UNUSED, siginfo_t *si EINA_UNUSED, @@ -46,16 +55,9 @@ _eina_debug_signal(int sig EINA_UNUSED, int i, slot = 0; pthread_t self = pthread_self(); clockid_t cid; - // XXX: use pthread_getcpuclockid() to get cpu time used since last poll - // - // clockid_t cid; - // struct timespec ts ts; - // pthread_getcpuclockid(pthread_self(), &cid); - // clock_gettime(cid, &ts); - // printf("%4ld.%03ld\n", ts.tv_sec, ts.tv_nsec / 1000000); - // - // also get current cpu with: - // getcpu() + + // find which slot in the array of threads we have so we store info + // in the correct slot for us if (self != _eina_debug_thread_mainloop) { for (i = 0; i < _eina_debug_thread_active_num; i++) @@ -66,23 +68,31 @@ _eina_debug_signal(int sig EINA_UNUSED, goto found; } } + // we couldn't find out thread reference! help! fprintf(stderr, "EINA DEBUG ERROR: can't find thread slot!\n"); eina_semaphore_release(&_eina_debug_monitor_return_sem, 1); return; } found: -// printf("dump into slot %i for %p\n", slot, (void *)self); + // store thread info like what cpu core we are on now (not reliable + // but hey - better than nothing), the amount of cpu time total + // we have consumed (it's cumulative so subtracing deltas can give + // you an average amount of cpu time consumed between now and the + // previous time we looked) and also a full backtrace _bt_cpu[slot] = sched_getcpu(); pthread_getcpuclockid(self, &cid); clock_gettime(cid, &(_bt_ts[slot])); -// _bt_buf_len[slot] = backtrace(_bt_buf[slot], EINA_MAX_BT); _bt_buf_len[slot] = _eina_debug_unwind_bt(_bt_buf[slot], EINA_MAX_BT); + // now wake up the monitor to let them know we are done collecting our + // backtrace info eina_semaphore_release(&_eina_debug_monitor_return_sem, 1); } +// we shall sue SIGPROF as out signal for pausing threads and having them +// dump a backtrace for polling based profiling #define SIG SIGPROF -//#define SIG ((SIGRTMIN + SIGRTMAX) / 2) +// a quick and dirty local time point getter func - not portable static inline double get_time(void) { @@ -110,19 +120,26 @@ _eina_debug_monitor(void *data EINA_UNUSED) double t0, t; fd_set rfds, wfds, exfds; struct timeval tv = { 0 }; + // some state for debugging unsigned int poll_time = 1000; Eina_Bool poll_on = EINA_FALSE; t0 = get_time(); + // sit forever processing commands or timeouts in the debug monitor + // thread - this is separate to the rest of the app so it shouldn't + // impact the application specifically for (;;) { int i; + // set up data for select like read fd's FD_ZERO(&rfds); FD_ZERO(&wfds); FD_ZERO(&exfds); + // the only fd we care about - out debug daemon connection FD_SET(_eina_debug_monitor_service_fd, &rfds); max_fd = _eina_debug_monitor_service_fd; + // if we are in a polling mode then set up a timeout and wait for it if (poll_on) { if ((tv.tv_sec == 0) && (tv.tv_usec == 0)) @@ -132,59 +149,42 @@ _eina_debug_monitor(void *data EINA_UNUSED) } ret = select(max_fd + 1, &rfds, &wfds, &exfds, &tv); } + // we have no timeout - so wait forever for a message from debugd else ret = select(max_fd + 1, &rfds, &wfds, &exfds, NULL); + // if the fd for debug daemon says it's alive, process it if ((ret == 1) && (FD_ISSET(_eina_debug_monitor_service_fd, &rfds))) { - unsigned int size; - int rret; - - // XXX: handle protocol - rret = read(_eina_debug_monitor_service_fd, &size, 4); - if ((rret == 4) && (size > 0) && (size < 63356)) - { - char *buf = alloca(size); + // collect a single op on the debug daemon control fd + char op[5]; + int size; + unsigned char *data; - rret = read(_eina_debug_monitor_service_fd, buf, size); - if ((rret == (int)size) && (size >= 4)) - { - if (!strncmp(buf, "PLON", 4)) - { - if (size >= 8) memcpy(&poll_time, buf + 4, 4); - poll_on = EINA_TRUE; - } - else if (!strncmp(buf, "PLOF", 4)) - { - poll_time = 1000; - poll_on = EINA_FALSE; - } - else - fprintf(stderr, "EINA DEBUG ERROR: Uunknown command\n"); - } - else - { - if (rret <= 0) - { - fprintf(stderr, "EINA DEBUG ERROR: Lost debug daemon!\n"); - goto fail; - } - else - { - } - } - } - else + // get the opcode and stor in op - guarantee its 0 byte terminated + data = NULL; + size = _eina_debug_monitor_service_read(op, &data); + // if not negative - we have a real message + if (size >= 0) { - if (rret <= 0) + // profiling on with poll time gap as uint payload + if (!strcmp(op, "PLON")) { - fprintf(stderr, "EINA_DEBUG ERROR: Lost debug daemon!\n"); - goto fail; + if (size >= 4) memcpy(&poll_time, data, 4); + poll_on = EINA_TRUE; } - else + // profiling off with no payload + else if (!strcmp(op, "PLOF")) { - fprintf(stderr, "EINA DEBUG ERROR: Invalid message size %i\n", size); - goto fail; + poll_time = 1000; + poll_on = EINA_FALSE; } + // something we don't understand + else fprintf(stderr, + "EINA DEBUG ERROR: " + "Uunknown command %s\n", op); + free(data); } + // major failure on debug daemon control fd - get out of here + else goto fail; } if (poll_on) @@ -195,15 +195,15 @@ _eina_debug_monitor(void *data EINA_UNUSED) _eina_debug_chunk_tmp_reset(); // get an array of pointers for the backtrace array for main + th _bt_buf = _eina_debug_chunk_tmp_push - ((1 + _eina_debug_thread_active_num) * sizeof(void *)); + ((1 + _eina_debug_thread_active_num) * sizeof(void *)); if (!_bt_buf) goto err; // get an array of pointers for the timespec array for mainloop + th _bt_ts = _eina_debug_chunk_tmp_push - ((1 + _eina_debug_thread_active_num) * sizeof(struct timespec)); + ((1 + _eina_debug_thread_active_num) * sizeof(struct timespec)); if (!_bt_ts) goto err; // get an array of pointers for the cpuid array for mainloop + th _bt_cpu = _eina_debug_chunk_tmp_push - ((1 + _eina_debug_thread_active_num) * sizeof(int)); + ((1 + _eina_debug_thread_active_num) * sizeof(int)); if (!_bt_cpu) goto err; // now get an array of void pts for mainloop bt _bt_buf[0] = _eina_debug_chunk_tmp_push(EINA_MAX_BT * sizeof(void *)); @@ -216,24 +216,26 @@ _eina_debug_monitor(void *data EINA_UNUSED) } // get an array of ints to stor the bt len for mainloop + threads _bt_buf_len = _eina_debug_chunk_tmp_push - ((1 + _eina_debug_thread_active_num) * sizeof(int)); + ((1 + _eina_debug_thread_active_num) * sizeof(int)); // collect bt from the mainloop - always there _eina_debug_collect_bt(_eina_debug_thread_mainloop); // now collect per thread for (i = 0; i < _eina_debug_thread_active_num; i++) - _eina_debug_collect_bt(_eina_debug_thread_active[i]); + _eina_debug_collect_bt(_eina_debug_thread_active[i]); // we're done probing. now collec all the "i'm done" msgs on the // semaphore for every thread + mainloop for (i = 0; i < (_eina_debug_thread_active_num + 1); i++) - eina_semaphore_lock(&_eina_debug_monitor_return_sem); + eina_semaphore_lock(&_eina_debug_monitor_return_sem); // we now have gotten all the data from all threadd + mainloop. // we can process it now as we see fit, so release thread lock +//// XXX: some debug so we can see the bt's we collect - will go // for (i = 0; i < (_eina_debug_thread_active_num + 1); i++) // { // _eina_debug_dump_fhandle_bt(stderr, _bt_buf[i], _bt_buf_len[i]); // } err: eina_spinlock_release(&_eina_debug_thread_lock); +//// XXX: some debug just to see how well we perform - will go bts++; if (bts >= 10000) { @@ -245,6 +247,7 @@ err: } } fail: + // we failed - get out of here and disconnect to debugd close(_eina_debug_monitor_service_fd); _eina_debug_monitor_service_fd = -1; return NULL; @@ -256,9 +259,9 @@ _eina_debug_monitor_thread_start(void) { int err; + // if it's already running - we're good. if (_monitor_thread_runs) return; - // XXX: set up socket conn to debug daemon and then have thread deal with - // it from there on + // create debug monitor thread err = pthread_create(&_monitor_thread, NULL, _eina_debug_monitor, NULL); if (err != 0) { @@ -273,6 +276,8 @@ _eina_debug_monitor_signal_init(void) { struct sigaction sa; + // set up signal handler for our profiling signal - eevery thread should + // obey this (this is the case on linux - other OSs may vary) sa.sa_sigaction = _eina_debug_signal; sa.sa_flags = SA_RESTART | SA_SIGINFO; sigemptyset(&sa.sa_mask); @@ -283,6 +288,7 @@ _eina_debug_monitor_signal_init(void) static const char * _socket_home_get() { + // get possible debug daemon socket directory base const char *dir = getenv("XDG_RUNTIME_DIR"); if (!dir) dir = getenv("HOME"); if (!dir) dir = getenv("TMPDIR"); diff --git a/src/lib/eina/eina_debug_proto.c b/src/lib/eina/eina_debug_proto.c index 44ab536..a8bac38 100644 --- a/src/lib/eina/eina_debug_proto.c +++ b/src/lib/eina/eina_debug_proto.c @@ -2,18 +2,106 @@ #ifdef EINA_HAVE_DEBUG +int +_eina_debug_monitor_service_send(int fd, const char op[4], + unsigned char *data, int size) +{ + // send protocol packet. all protocol is an int for size of packet then + // included in that size (so a minimum size of 4) is a 4 byte opcode + // (all opcodes are 4 bytes as a string of 4 chars), then the real + // message payload as a data blob after that + unsigned char *buf = alloca(4 + 4 + size); + int newsize = size + 4; + memcpy(buf, &newsize, 4); + memcpy(buf + 4, op, 4); + if (size > 0) memcpy(buf + 8, data, size); + return write(fd, buf, newsize + 4); +} + void _eina_debug_monitor_service_greet(void) { - const char *hello = "HELO"; - unsigned int version = 1; - unsigned int msize = 4 + 4 + 4; - unsigned int pid = getpid(); - unsigned char buf[16]; - memcpy(buf + 0, &msize, 4); - memcpy(buf + 4, hello, 4); - memcpy(buf + 8, &version, 4); - memcpy(buf + 12, &pid, 4); - write(_eina_debug_monitor_service_fd, buf, sizeof(buf)); + // say hello to our debug daemon - tell them our PID and protocol + // version we speak + unsigned char buf[8]; + int version = 1; // version of protocol we speak + int pid = getpid(); + memcpy(buf + 0, &version, 4); + memcpy(buf + 4, &pid, 4); + _eina_debug_monitor_service_send(_eina_debug_monitor_service_fd, + "HELO", buf, sizeof(buf)); +} + +int +_eina_debug_monitor_service_read(char *op, unsigned char **data) +{ + unsigned char buf[8]; + unsigned int size; + int rret; + + // read first 8 bytes - payload size (excl size header) with 4 byte + // opcode that always has to be there + rret = read(_eina_debug_monitor_service_fd, buf, 8); + if (rret == 8) + { + // store size in int - native endianess as it's local + memcpy(&size, buf, 4); + // min size of course is 4 (just opcode) and we will have a max + // size for any packet of 1mb here coming from debug daemon + // for sanity + if ((size >= 4) && (size <= (1024 * 1024))) + { + // store 4 byte opcode and guarantee it's 0 byte terminated + memcpy(op, buf + 4, 4); + op[4] = 0; + // subtract space for opcode + size -= 4; + // if we have no payload - move on + if (size == 0) *data = NULL; + else + { + // allocate a buffer for real payload + *data = malloc(size); + if (*data) + { + // get payload - blocking!!!! + rret = read(_eina_debug_monitor_service_fd, *data, size); + if (rret != (int)size) + { + // we didn't get payload as expected - error on + // comms + fprintf(stderr, + "EINA DEBUG ERROR: " + "Invalid Debug opcode read of %i\n", rret); + free(*data); + *data = NULL; + return -1; + } + } + else + { + // we couldn't allocate memory for payloa buffer + // internal memory limit error + fprintf(stderr, + "EINA DEBUG ERROR: " + "Cannot allocate %u bytes for op\n", size); + return -1; + } + } + // return payload size (< 0 is an error) + return size; + } + else + { + fprintf(stderr, + "EINA DEBUG ERROR: " + "Invalid opcode size of %u\n", size); + return -1; + } + } + fprintf(stderr, + "EINA DEBUG ERROR: " + "Invalid opcode read %i != 8\n", rret); + return -1; } #endif -- 2.7.4