[FIX] wrong app start time
[platform/core/system/swap-probe.git] / helper / libdaprobe.c
1 /*
2  *  DA probe
3  *
4  * Copyright (c) 2000 - 2013 Samsung Electronics Co., Ltd. All rights reserved.
5  *
6  * Contact: 
7  *
8  * Jaewon Lim <jaewon81.lim@samsung.com>
9  * Woojin Jung <woojin2.jung@samsung.com>
10  * Juyoung Kim <j0.kim@samsung.com>
11  * Nikita Kalyazin <n.kalyazin@samsung.com>
12  * Anastasia Lyupa <a.lyupa@samsung.com>
13  * 
14  * This library is free software; you can redistribute it and/or modify it under
15  * the terms of the GNU Lesser General Public License as published by the
16  * Free Software Foundation; either version 2.1 of the License, or (at your option)
17  * any later version.
18  * 
19  * This library is distributed in the hope that it will be useful, but WITHOUT ANY
20  * WARRANTY; without even the implied warranty of MERCHANTABILITY or
21  * FITNESS FOR A PARTICULAR PURPOSE. See the GNU Lesser General Public
22  * License for more details.
23  *
24  * You should have received a copy of the GNU Lesser General Public License
25  * along with this library; if not, write to the Free Software Foundation, Inc., 51
26  * Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA
27  *
28  * Contributors:
29  * - S-Core Co., Ltd
30  * - Samsung RnD Institute Russia
31  * 
32  */
33
34 #include <stdio.h>                      // for sprintf
35 #include <stdlib.h>                     // for getenv
36 #include <string.h>                     // for strstr
37 #include <stdbool.h>            // for bool
38 #include <stdint.h>                     // fot uint32_t,uint64_t
39 #include <stdarg.h>                     // for va_list, va_arg(__appendTypeLog)
40 #include <execinfo.h>           // for backtrace, backtrace_symbols
41 #include <unistd.h>                     // for write, alarm function, syscall
42 #include <pthread.h>            // for pthread_mutex_lock
43 #include <signal.h>
44
45 #include <sys/syscall.h>        // for syscall
46 #include <sys/time.h>           // for gettimeofday
47 #include <sys/socket.h>         // for socket, connect
48 #include <sys/un.h>                     // for sockaddr_un
49 #include <sys/timerfd.h>        // for timerfd
50
51 #include "probeinfo.h"
52 #include "dautil.h"
53 #include "dahelper.h"
54 #include "dacollection.h"
55
56 #include "binproto.h"
57
58 #define APP_INSTALL_PATH                "/opt/apps"
59 #define OSP_APP_POSTFIX                 ".exe"
60 #define UDS_NAME                                "/tmp/da.socket"
61 #define TIMERFD_INTERVAL                100000000               // 0.1 sec
62
63 __thread int            gProbeBlockCount = 0;
64 __thread int            gProbeDepth = 0;
65 __thread pid_t          gTid = -1;
66
67 int                     g_timerfd = 0;
68 long            g_total_alloc_size = 0;
69 pthread_t       g_recvthread_id;
70
71 int log_fd = 0;
72
73 int getExecutableMappingAddress();
74
75 bool printLog(log_t* log, int msgType);
76 /******************************************************************************
77  * internal functions
78    (this means that these functions do not need to set enter/exit flag)
79  ******************************************************************************/
80
81 // runtime configure the probe option
82 static void _configure(char* configstr)
83 {
84         char buf[64];
85         gTraceInfo.optionflag = atoi(configstr);
86
87         sprintf(buf, "configure in probe : %s, %lx\n", configstr, gTraceInfo.optionflag);
88         PRINTMSG(buf);
89 }
90
91 // create socket to daemon and connect
92 static int createSocket(void)
93 {
94         ssize_t recvlen;
95         int clientLen, ret = 0;
96         struct sockaddr_un clientAddr;
97         char buf[16];
98         log_t log;
99
100         if((gTraceInfo.socket.daemonSock = socket(AF_UNIX, SOCK_STREAM | SOCK_CLOEXEC, 0)) != -1)
101         {
102                 bzero(&clientAddr, sizeof(clientAddr));
103                 clientAddr.sun_family = AF_UNIX;
104                 sprintf(clientAddr.sun_path, "%s", UDS_NAME);
105
106                 clientLen = sizeof(clientAddr);
107                 if(connect(gTraceInfo.socket.daemonSock, (struct sockaddr *)&clientAddr, clientLen) >= 0)
108                 {
109                         // recv initial configuration value
110                         recvlen = recv(gTraceInfo.socket.daemonSock, &log,
111                                         sizeof(log.type) + sizeof(log.length), MSG_WAITALL);
112
113                         if(recvlen > 0) // recv succeed
114                         {
115                                 if(log.length > 0)
116                                 {
117                                         if(log.length >= DA_LOG_MAX)
118                                                 log.length = DA_LOG_MAX - 1;
119                                         recvlen = recv(gTraceInfo.socket.daemonSock, log.data,
120                                                 log.length, MSG_WAITALL);
121                                 }
122                                 else
123                                 {
124                                         log.length = 0;
125                                 }
126
127                                 log.data[log.length] = '\0';
128
129                                 if(log.type == MSG_CONFIG)
130                                 {
131                                         _configure(log.data);
132                                 }
133                                 else
134                                 {
135                                         // unexpected case
136                                 }
137                         }
138                         else if(recvlen < 0)
139                         {
140                                 char buf[64];
141                                 sprintf(buf, "recv failed in socket creation with error(%d)\n", recvlen);
142                         }
143                         else    // closed by other peer
144                         {
145
146                         }
147                         sprintf(buf, "%d|%llu", getpid(), gTraceInfo.app.startTime);
148                         printLogStr(buf, MSG_PID);
149                         PRINTMSG("createSocket connect() success\n");
150                 }
151                 else
152                 {
153                         close(gTraceInfo.socket.daemonSock);
154                         gTraceInfo.socket.daemonSock = -1;
155                         ret = -1;
156                 }
157         }
158         else
159         {
160                 ret = -1;
161         }
162
163         return ret;
164 }
165
166
167 // parse backtrace string and find out the caller of probed api function
168 // return 0 if caller is user binary, otherwise return 1
169 static int determineCaller(char* tracestring)
170 {
171         char *substr;
172
173         // determine whether saveptr (caller binary name) is user binary or not
174         substr = strstr(tracestring, APP_INSTALL_PATH);
175
176         if(substr == NULL)      // not user binary
177         {
178                 return 1;
179         }
180         else                            // user binary
181         {
182 #ifdef OSPAPP
183                 substr = strstr(tracestring, OSP_APP_POSTFIX);
184                 if(substr == NULL)
185                         return 1;
186 #endif
187                 return 0;
188         }
189 }
190
191 // return current thread id
192 static pid_t _gettid()
193 {
194         if(gTid == -1)
195                 gTid = syscall(__NR_gettid);    // syscall is very expensive
196         return gTid;
197 }
198
199 static void* recvThread(void* data)
200 {
201         fd_set readfds, workfds;
202         int maxfd = 0, rc;
203         uint64_t xtime;
204         ssize_t recvlen;
205         log_t log;
206         sigset_t profsigmask;
207
208         if(gTraceInfo.socket.daemonSock == -1)
209                 return NULL;
210
211         probeBlockStart();
212
213         sigemptyset(&profsigmask);
214         sigaddset(&profsigmask, SIGPROF);
215         pthread_sigmask(SIG_BLOCK, &profsigmask, NULL);
216
217         FD_ZERO(&readfds);
218         if(g_timerfd > 0)
219         {
220                 maxfd = g_timerfd;
221                 FD_SET(g_timerfd, &readfds);
222         }
223         if(maxfd < gTraceInfo.socket.daemonSock)
224                 maxfd = gTraceInfo.socket.daemonSock;
225         FD_SET(gTraceInfo.socket.daemonSock, &readfds);
226
227         while(1)
228         {
229                 workfds = readfds;
230                 rc = select(maxfd + 1, &workfds, NULL, NULL, NULL);
231                 if(rc < 0)
232                 {
233                         continue;
234                 }
235
236                 if(g_timerfd > 0 && FD_ISSET(g_timerfd, &workfds))
237                 {
238                         recvlen = read(g_timerfd, &xtime, sizeof(xtime));
239                         if(recvlen > 0)
240                         {
241                                 log.length = sprintf(log.data, "%ld", g_total_alloc_size);
242                                 printLog(&log, MSG_ALLOC);
243                         }
244                         else
245                         {
246                                 // read failed
247                         }
248                         continue;
249                 }
250                 else if(FD_ISSET(gTraceInfo.socket.daemonSock, &workfds))
251                 {
252                         recvlen = recv(gTraceInfo.socket.daemonSock, &log,
253                                         sizeof(log.type) + sizeof(log.length), MSG_WAITALL);
254
255                         if(recvlen > 0) // recv succeed
256                         {
257                                 if(log.length > 0)
258                                 {
259                                         if(log.length >= DA_LOG_MAX)
260                                                 log.length = DA_LOG_MAX - 1;
261                                         recvlen = recv(gTraceInfo.socket.daemonSock, log.data,
262                                                 log.length, MSG_WAITALL);
263                                 }
264                                 else
265                                 {
266                                         log.length = 0;
267                                 }
268
269                                 log.data[log.length] = '\0';
270
271                                 if(log.type == MSG_CONFIG)
272                                 {
273                                         _configure(log.data);
274                                 }
275                                 else if(log.type == MSG_STOP)
276                                 {
277                                         exit(0);
278                                 }
279                                 else
280                                 {
281                                         char buf[64];
282                                         sprintf(buf, "recv unknown message(%d)\n", log.type);
283                                         continue;
284                                 }
285                         }
286                         else if(recvlen == 0)   // closed by other peer
287                         {
288                                 close(gTraceInfo.socket.daemonSock);
289                                 gTraceInfo.socket.daemonSock = -1;
290                                 break;
291                         }
292                         else    // recv error
293                         {
294                                 char buf[64];
295                                 sprintf(buf, "recv failed in recv thread with error(%d)\n", recvlen);
296                                 continue;
297                         }
298                 }
299                 else    // unknown case
300                 {
301                         continue;
302                 }
303         }
304
305         probeBlockEnd();
306         return NULL;
307 }
308
309 /*****************************************************************************
310  * initialize / finalize function
311  *****************************************************************************/
312
313 void __attribute__((constructor)) _init_probe()
314 {
315         struct timeval ttime;
316         struct itimerspec ctime;
317
318         probeBlockStart();
319
320         initialize_hash_table();
321
322         initialize_screencapture();
323
324         initialize_event();
325
326         getExecutableMappingAddress();
327
328         // get app start time
329         gettimeofday(&ttime, NULL);
330         gTraceInfo.app.startTime = (uint64_t)ttime.tv_sec * 1000 * 1000
331                 + ttime.tv_usec;
332
333         // create socket for communication with da_daemon
334         if(createSocket() == 0)
335         {
336                 // create timerfd
337                 g_timerfd = timerfd_create(CLOCK_REALTIME, TFD_CLOEXEC);
338                 if(g_timerfd > 0)
339                 {
340                         ctime.it_value.tv_sec = 0;
341                         ctime.it_value.tv_nsec = TIMERFD_INTERVAL;
342                         ctime.it_interval.tv_sec = 0;
343                         ctime.it_interval.tv_nsec = TIMERFD_INTERVAL;
344                         if(0 > timerfd_settime(g_timerfd, 0, &ctime, NULL))
345                         {
346                                 PRINTMSG("failed to set timerfd\n");
347                                 close(g_timerfd);
348                                 g_timerfd = 0;
349                         }
350                 }
351                 else
352                 {
353                         PRINTMSG("failed to create timerdf\n");
354                 }
355
356                 // create recv Thread
357                 if(pthread_create(&g_recvthread_id, NULL, recvThread, NULL) < 0)        // thread creation failed
358                 {
359                         PRINTMSG("failed to crate recv thread\n");
360                 }
361                 update_heap_memory_size(true, 0);
362         }
363         else
364         {
365
366         }
367
368         PRINTMSG("dynamic analyzer probe helper so loading...\n");
369
370         gTraceInfo.init_complete = 1;
371         probeBlockEnd();
372 }
373
374 void __attribute__((destructor)) _fini_probe()
375 {
376         int i;
377         probeBlockStart();
378
379         gTraceInfo.init_complete = -1;
380         PRINTMSG("dynamic analyzer probe helper so unloading...\n");
381
382         remove_all_glist();
383
384         // close timerfd
385         if(g_timerfd > 0)
386                 close(g_timerfd);
387
388         // close socket
389         if(gTraceInfo.socket.daemonSock != -1)
390         {
391                 printLogStr(NULL, MSG_TERMINATE);
392                 close(gTraceInfo.socket.daemonSock);
393                 gTraceInfo.socket.daemonSock = -1;
394         }
395
396         finalize_event();
397
398         finalize_screencapture();
399
400         finalize_hash_table();
401
402         for(i = 0; i < NUM_ORIGINAL_LIBRARY; i++)
403         {
404                 if(lib_handle[i] != NULL)
405                 {
406                         dlclose(lib_handle[i]);
407                 }
408         }
409
410         probeBlockEnd();
411 }
412
413
414 /**************************************************************************
415  * Helper APIs
416  **************************************************************************/
417
418 /************************************************************************
419  * manipulate and print log functions
420  ************************************************************************/
421
422 bool printLog(log_t* log, int msgType)
423 {
424         int res;
425         if(unlikely(gTraceInfo.socket.daemonSock == -1))
426                 return false;
427
428         if(unlikely(log == NULL))
429                 return false;
430
431         probeBlockStart();
432         log->type = msgType;
433         pthread_mutex_lock(&(gTraceInfo.socket.sockMutex));
434         res = send(gTraceInfo.socket.daemonSock, log, sizeof(log->type) + sizeof(log->length) + log->length, 0);
435         pthread_mutex_unlock(&(gTraceInfo.socket.sockMutex));
436         probeBlockEnd();
437
438         return true;
439 }
440
441 bool printLogStr(const char* str, int msgType)
442 {
443         int res;
444         log_t log;
445
446         if(unlikely(gTraceInfo.socket.daemonSock == -1))
447                 return false;
448
449         probeBlockStart();
450
451         log.type = msgType;
452         if(str)
453         {
454                 sprintf(log.data, "%s", str);
455                 log.length = strlen(str);
456         }
457         else
458         {
459                 log.length = 0;
460         }
461
462         pthread_mutex_lock(&(gTraceInfo.socket.sockMutex));
463         res = send(gTraceInfo.socket.daemonSock, &log, sizeof(log.type) + sizeof(log.length) + log.length, MSG_DONTWAIT);
464         pthread_mutex_unlock(&(gTraceInfo.socket.sockMutex));
465
466         probeBlockEnd();
467
468         return true;
469 }
470
471 // return 0 for successful case
472 // return non-zero for error
473 // if token is NULL then use DEFAULT TOKEN "`,"
474 // if token is not NULL then insert DEFAULT TOKEN before append input
475 int __appendTypeLog(log_t* log, int nInput, char* token, ...)
476 {
477         static char* default_token = DEFAULT_TOKEN;
478         va_list p_arg;
479         int i, type;
480         char* seperator = default_token;
481
482         if(nInput <= 0 || log == NULL)
483                 return -1;
484
485         probeBlockStart();
486
487         va_start(p_arg, token);
488
489         if(token != NULL)
490                 seperator = token;
491
492         for(i = 0; i < nInput; i++)
493         {
494                 type = va_arg(p_arg, int);
495
496                 if(likely(log->length > 0))     // append token or default token
497                 {
498                         if(unlikely(i == 0))
499                                 log->length += sprintf(log->data + log->length, "%s", default_token);
500                         else
501                                 log->length += sprintf(log->data + log->length, "%s", seperator);
502                 }
503
504                 switch(type)
505                 {
506                 case VT_INT:
507                         log->length += sprintf(log->data + log->length, "%d", va_arg(p_arg, int));
508                         break;
509                 case VT_UINT:
510                         log->length += sprintf(log->data + log->length, "%u", va_arg(p_arg, unsigned int));
511                         break;
512                 case VT_LONG:
513                         log->length += sprintf(log->data + log->length, "%ld", va_arg(p_arg, long));
514                         break;
515                 case VT_ULONG:
516                         log->length += sprintf(log->data + log->length, "%lu", va_arg(p_arg, unsigned long));
517                         break;
518                 case VT_STR:
519                         log->length += sprintf(log->data + log->length, "%s", va_arg(p_arg, char*));
520                         break;
521                 case VT_CHAR:   // 'char' is promoted to 'int' when passed through '...'
522                         log->length += sprintf(log->data + log->length, "%c", va_arg(p_arg, int));
523                         break;
524                 case VT_PTR:
525                         log->length += sprintf(log->data + log->length, "%p", va_arg(p_arg, void*));
526                         break;
527                 case VT_NULL:
528                         va_arg(p_arg, unsigned int);
529                         break;
530                 case VT_OFF_T:
531                         log->length += sprintf(log->data + log->length, "%ld", va_arg(p_arg, off_t));
532                         break;
533                 case VT_SIZE_T:
534                         log->length += sprintf(log->data + log->length, "%u", va_arg(p_arg, size_t));
535                         break;
536                 case VT_SSIZE_T:
537                         log->length += sprintf(log->data + log->length, "%d", va_arg(p_arg, ssize_t));
538                         break;
539                 case VT_SOCKLEN_T:
540                         log->length += sprintf(log->data + log->length, "%u", va_arg(p_arg, socklen_t));
541                         break;
542                 case VT_UINT16_T:       // 'uint16_t' is promoted to 'int' when passed through '...'
543                         log->length += sprintf(log->data + log->length, "%u", va_arg(p_arg, int));
544                         break;
545                 case VT_UINT32_T:
546                         log->length += sprintf(log->data + log->length, "%u", va_arg(p_arg, uint32_t));
547                         break;
548                 case VT_UINT64_T:
549                         log->length += sprintf(log->data + log->length, "%llu", va_arg(p_arg, uint64_t));
550                         break;
551                 case VT_MODE_T:
552                         log->length += sprintf(log->data + log->length, "%u", va_arg(p_arg, mode_t));
553                         break;
554 /*              case VT_DEV_T:
555                         log->length += sprintf(log->data + log->length, "%lu", va_arg(p_arg, dev_t));
556                         break;
557                 case VT_NFDS_T:
558                         log->length += sprintf(log->data + log->length, "%lu", va_arg(p_arg, nfds_t));
559                         break;*/
560                 default:
561                         va_end(p_arg);
562                         probeBlockEnd();
563                         return -1;
564                 }
565         }
566
567         va_end(p_arg);
568
569         probeBlockEnd();
570         return 0;
571 }
572
573 // get backtrace string
574 // return stack depth if succeed, otherwise return 0
575 // parameter 'log' cannot be null
576 int getBacktraceString(log_t* log, int bufsize)
577 {
578         void* array[MAX_STACK_DEPTH];
579         char** strings = NULL;
580         size_t i, size;
581         int initsize;
582         int stringlen;
583
584         if(log == NULL)
585                 return 0;
586
587         probeBlockStart();
588
589         initsize = log->length;
590         log->data[log->length] = '\0';  // is this necessary ?
591         size = backtrace(array, MAX_STACK_DEPTH);
592         if(likely(size > TRIM_STACK_DEPTH))
593         {
594                 strings = BACKTRACE_SYMBOLS(array + TRIM_STACK_DEPTH, size - TRIM_STACK_DEPTH);
595
596                 if(likely(strings != NULL))
597                 {
598                         for(i = TRIM_STACK_DEPTH; i < size; i++)
599                         {
600                                 stringlen = strlen(strings[i - TRIM_STACK_DEPTH]) + 14;
601                                 if(log->length + stringlen >= bufsize + initsize)
602                                         break;
603
604                                 log->length += sprintf(log->data + log->length, "%010u`,%s`,", (unsigned int)(array[i]), strings[i - TRIM_STACK_DEPTH]);
605                         }
606                         log->data[log->length-2] = '\0';
607                         log->length -= 2;
608                         free(strings);
609                 }
610                 else    // failed to get backtrace symbols
611                 {
612                         // just print trace address
613                         for(i = TRIM_STACK_DEPTH; i < size; i++)
614                         {
615                                 stringlen = 23;
616                                 if(log->length + stringlen >= bufsize + initsize)
617                                         break;
618
619                                 log->length += sprintf(log->data + log->length, "%010u`,(unknown)`,", (unsigned int)(array[i]));
620                         }
621                         log->data[log->length-2] = '\0';
622                         log->length -= 2;
623                 }
624
625                 probeBlockEnd();
626                 return (int)(size - TRIM_STACK_DEPTH);
627         }
628         else
629         {
630                 probeBlockEnd();
631                 return 0;
632         }
633 }
634
635 /*************************************************************************
636  * probe block control functions
637  *************************************************************************/
638 int preBlockBegin(void* caller, bool bFiltering, enum DaOptions option)
639 {
640         bool user = false;
641         void* tarray[1];
642         char** strings;
643
644         if(gProbeBlockCount != 0 || gProbeDepth != 0)
645                 return 0;
646
647         if(gTraceInfo.init_complete <= 0)
648                 return 0;
649
650         if((gTraceInfo.optionflag & option) == 0)
651                 return 0;
652
653         probeBlockStart();
654
655         if(gTraceInfo.exec_map.map_start != NULL)
656         {
657                 // address comparison
658                 if(caller >= gTraceInfo.exec_map.map_start &&
659                                 caller <= gTraceInfo.exec_map.map_end)
660                 {
661                         user = true;
662                 }
663                 else
664                 {
665                         // nothing to do
666                 }
667         }
668         else
669         {
670                 // backtrace for filtering
671                 tarray[0] = caller;
672                 strings = BACKTRACE_SYMBOLS(tarray, 1);
673                 if(strings != NULL)
674                 {
675                         if((determineCaller(strings[0]) == 0))
676                                 user = true;
677                         free(strings);
678                 }
679                 else
680                 {
681                         // nothing to do
682                 }
683         }
684
685         if(user)
686         {
687                 probingStart();
688                 return 2;       // user call
689         }
690         else
691         {
692                 if(bFiltering)
693                 {
694                         probeBlockEnd();
695                         return 0;       // not probing
696                 }
697                 else
698                 {
699                         probingStart();
700                         return 1;       // internal call
701                 }
702         }
703 }
704
705 int postBlockBegin(int preresult)
706 {
707         if(preresult)
708         {
709                 probeBlockStart();
710         }
711
712         return preresult;
713 }
714
715 void preBlockEnd()
716 {
717         probeBlockEnd();
718 }
719
720 void postBlockEnd()
721 {
722         probingEnd();
723         probeBlockEnd();
724 }
725
726 /*************************************************************************
727  * helper info getter functions
728  *************************************************************************/
729 // return current time in 1/10000 sec unit
730 unsigned long getCurrentTime()
731 {
732         struct timeval cTime;
733
734         gettimeofday(&cTime, NULL);
735
736         return (unsigned long)((cTime.tv_sec * 10000 + (cTime.tv_usec/100)));
737 }
738
739 unsigned int getCurrentEventIndex()
740 {
741         return gTraceInfo.index.eventIndex;
742 }
743
744 /************************************************************************
745  * probe functions
746  ************************************************************************/
747 bool setProbePoint(probeInfo_t* iProbe)
748 {
749         if(unlikely(iProbe == NULL))
750         {
751                 return false;
752         }
753
754         probeBlockStart();
755
756         // atomic operaion(gcc builtin) is more expensive then pthread_mutex
757         pthread_mutex_lock(&(gTraceInfo.index.eventMutex));     
758         iProbe->eventIndex = gTraceInfo.index.eventIndex++;
759         pthread_mutex_unlock(&(gTraceInfo.index.eventMutex));
760
761         iProbe->currentTime = getCurrentTime();
762         iProbe->pID = getpid();
763         iProbe->tID = _gettid();
764         iProbe->callDepth = gProbeDepth;
765
766         probeBlockEnd();
767         return true;
768 }
769
770 // update heap memory size through socket
771 // return 0 if size is updated through socket
772 // return 1 if size is updated into global variable
773 int update_heap_memory_size(bool isAdd, size_t size)
774 {
775         long tmp;
776         if(isAdd)
777         {
778                 tmp = __sync_add_and_fetch(&g_total_alloc_size, (long)size);
779         }
780         else
781         {
782                 tmp = __sync_sub_and_fetch(&g_total_alloc_size, (long)size);
783         }
784
785         return 0;
786 }
787
788