Set proper executable bits
[platform/core/system/dlog.git] / src / shared / logprint.c
1 /*
2  * DLOG
3  * Copyright (c) 2005-2008, The Android Open Source Project
4  * Copyright (c) 2012-2013 Samsung Electronics Co., Ltd.
5  *
6  * Licensed under the Apache License, Version 2.0 (the License);
7  * you may not use this file except in compliance with the License.
8  * You may obtain a copy of the License at
9  *
10  *     http://www.apache.org/licenses/LICENSE-2.0
11  *
12  * Unless required by applicable law or agreed to in writing, software
13  * distributed under the License is distributed on an "AS IS" BASIS,
14  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
15  * See the License for the specific language governing permissions and
16  * limitations under the License.
17  */
18
19 #include <stdio.h>
20 #include <stdlib.h>
21 #include <ctype.h>
22
23 #include <logprint.h>
24
25 typedef struct FilterInfo_t {
26         char *mTag;
27         log_priority mPri;
28         struct FilterInfo_t *p_next;
29 } FilterInfo;
30
31 struct log_format_t {
32         log_priority global_pri;
33         FilterInfo *filters;
34         log_print_format format;
35 };
36
37 /**
38  * @brief Allocate filter info
39  * @details Allocates filter info with given parameters
40  * @param[in] tag The filtering tag
41  * @param[in] pri The filtering priority
42  * @return The new structure (or NULL if allocation failed).
43  * @see filterinfo_free
44  */
45 static FilterInfo * filterinfo_new(const char *tag, log_priority pri)
46 {
47         FilterInfo *p_ret;
48         p_ret = (FilterInfo *)calloc(1, sizeof(FilterInfo));
49         if (!p_ret)
50                 return NULL;
51         p_ret->mTag = strdup(tag);
52         p_ret->mPri = pri;
53
54         return p_ret;
55 }
56
57 /**
58  * @brief Deallocate filter info
59  * @details Deallocates the entire filter info structure
60  * @param[in] p_info The structure to deallocate
61  * @see filterinfo_new
62  */
63 static void filterinfo_free(FilterInfo *p_info)
64 {
65         if (p_info == NULL)
66                 return;
67
68         free(p_info->mTag);
69         p_info->mTag = NULL;
70         free(p_info);
71 }
72
73 /**
74  * @brief Char to priority
75  * @details Converts a character priority representation to integer
76  * @param[in] c The character to convert
77  * @remarks Accepts both letters and numbers
78  * @return Integral log priority
79  * @see filter_pri_to_char
80  */
81 static log_priority filter_char_to_pri(char c)
82 {
83         log_priority pri;
84
85         c = tolower(c);
86
87         if (c >= '0' && c <= '9') {
88                 if (c >= ('0'+DLOG_SILENT))
89                         pri = DLOG_VERBOSE;
90                 else
91                         pri = (log_priority)(c - '0');
92         } else if (c == 'v') {
93                 pri = DLOG_VERBOSE;
94         } else if (c == 'd') {
95                 pri = DLOG_DEBUG;
96         } else if (c == 'i') {
97                 pri = DLOG_INFO;
98         } else if (c == 'w') {
99                 pri = DLOG_WARN;
100         } else if (c == 'e') {
101                 pri = DLOG_ERROR;
102         } else if (c == 'f') {
103                 pri = DLOG_FATAL;
104         } else if (c == 's') {
105                 pri = DLOG_SILENT;
106         } else if (c == '*') {
107                 pri = DLOG_DEFAULT;
108         } else {
109                 pri = DLOG_UNKNOWN;
110         }
111
112         return pri;
113 }
114 /**
115  * @brief Priority to character
116  * @details Converts an integer representation of priority to character
117  * @param[in] pri The integer to convert
118  * @return Character log priority
119  * @see filter_char_to_pri
120  */
121 static char filter_pri_to_char(log_priority pri)
122 {
123         switch (pri) {
124         case DLOG_VERBOSE:
125                 return 'V';
126         case DLOG_DEBUG:
127                 return 'D';
128         case DLOG_INFO:
129                 return 'I';
130         case DLOG_WARN:
131                 return 'W';
132         case DLOG_ERROR:
133                 return 'E';
134         case DLOG_FATAL:
135                 return 'F';
136         case DLOG_SILENT:
137                 return 'S';
138         case DLOG_DEFAULT:
139         case DLOG_UNKNOWN:
140         default:
141                 return '?';
142         }
143 }
144
145 /**
146  * @brief Tag's priority
147  * @details Figures out the priority associated with given tag
148  * @param[in] p_format The log format to work with
149  * @param[in] tag The tag whose priority to search for
150  * @return The tag's log priority
151  */
152 log_priority filter_pri_for_tag(log_format *p_format, const char *tag)
153 {
154         FilterInfo *p_curFilter;
155
156         for (p_curFilter = p_format->filters; p_curFilter != NULL; p_curFilter = p_curFilter->p_next) {
157                 if (0 == strcmp(tag, p_curFilter->mTag)) {
158                         if (p_curFilter->mPri == DLOG_DEFAULT)
159                                 return p_format->global_pri;
160                         else
161                                 return p_curFilter->mPri;
162                 }
163         }
164         return p_format->global_pri;
165 }
166
167 /**
168  * @brief Filter a line
169  * @details Passes a line through filters to discover whether it should be logged or not
170  * @param[in] p_format The format to work with
171  * @param[in] tag The line's tag
172  * @param[in] pri The line's priority
173  * @return True if the line should be printed, else false
174  */
175 int log_should_print_line(log_format *p_format, const char *tag, log_priority pri)
176 {
177         return pri >= filter_pri_for_tag(p_format, tag);
178 }
179
180 /**
181  * @brief Allocate log format
182  * @details Allocates a log format structure
183  * @return The new structure (or NULL if allocation failed).
184  * @see log_format_free
185  */
186 log_format *log_format_new(void)
187 {
188         log_format *p_ret;
189
190         p_ret = calloc(1, sizeof(log_format));
191
192         if (!p_ret)
193                 return NULL;
194         p_ret->global_pri = DLOG_SILENT;
195         p_ret->format = FORMAT_BRIEF;
196
197         return p_ret;
198 }
199
200 /**
201  * @brief Copy a log format
202  * @details Allocates a copy of the log format
203  * @param[in] p_format The log format to copy
204  * @return The new structure (or NULL if allocation failed)
205  * @see log_format_free
206  */
207 log_format *log_format_from_format(log_format *p_format)
208 {
209         log_format *p_ret;
210         FilterInfo *p_info, *p_info_old = NULL;
211
212         if (!(p_ret = log_format_new()))
213                 return NULL;
214
215         *p_ret = *p_format;
216
217         p_info = p_format->filters;
218
219         while (p_info != NULL) {
220                 FilterInfo *p_tmp;
221                 p_tmp = filterinfo_new(p_info->mTag, p_info->mPri);
222                 if (!p_tmp) {
223                         log_format_free(p_ret);
224                         return NULL;
225                 }
226
227                 if (!p_info_old)
228                         p_format->filters = p_tmp;
229                 else
230                         p_info_old->p_next = p_tmp;
231
232                 p_info_old = p_tmp;
233                 p_info = p_info->p_next;
234         }
235         return p_ret;
236 }
237
238 /**
239  * @brief Deallocate log format
240  * @details Deallocates the entire log format structure
241  * @param[in] p_format The structure to deallocate
242  */
243 void log_format_free(log_format *p_format)
244 {
245         FilterInfo *p_info;
246
247         p_info = p_format->filters;
248
249         while (p_info != NULL) {
250                 FilterInfo *p_info_old = p_info;
251                 p_info = p_info->p_next;
252                 filterinfo_free(p_info_old);
253         }
254
255         free(p_format);
256 }
257
258 /**
259  * @brief Set print format
260  * @detail Sets a log format's print format
261  * @param[in] p_format The log format whose print format to set
262  * @param[in] format The print format
263  */
264 void log_set_print_format(log_format *p_format, log_print_format format)
265 {
266         p_format->format = format;
267 }
268
269 /**
270  * @brief Print format from string
271  * @details Converts a string to print format
272  * @param[in] formatString The string representation to convert
273  * @return The integer print format (on invalid string: FORMAT_OFF)
274  */
275 log_print_format log_format_from_string(const char * formatString)
276 {
277         static log_print_format format;
278
279         if (strcmp(formatString, "brief") == 0)
280                 format = FORMAT_BRIEF;
281         else if (strcmp(formatString, "process") == 0)
282                 format = FORMAT_PROCESS;
283         else if (strcmp(formatString, "tag") == 0)
284                 format = FORMAT_TAG;
285         else if (strcmp(formatString, "thread") == 0)
286                 format = FORMAT_THREAD;
287         else if (strcmp(formatString, "raw") == 0)
288                 format = FORMAT_RAW;
289         else if (strcmp(formatString, "time") == 0)
290                 format = FORMAT_TIME;
291         else if (strcmp(formatString, "threadtime") == 0)
292                 format = FORMAT_THREADTIME;
293         else if (strcmp(formatString, "kerneltime") == 0)
294                 format = FORMAT_KERNELTIME;
295         else if (strcmp(formatString, "long") == 0)
296                 format = FORMAT_LONG;
297         else format = FORMAT_OFF;
298
299         return format;
300 }
301
302 /**
303  * @brief Add a filter rule
304  * @details Adds a tag/priority filtering rule
305  * @param[in] p_format The log format to add the filter rule to
306  * @param[in] filterExpression A filter expression ("tag:prio")
307  * @return 0 on success, else -1
308  * @remarks Assumes single threaded execution
309  */
310 int log_add_filter_rule(log_format *p_format,
311                 const char *filterExpression)
312 {
313         size_t tagNameLength;
314         log_priority pri = DLOG_DEFAULT;
315
316         tagNameLength = strcspn(filterExpression, ":");
317
318         if (tagNameLength == 0)
319                 goto error;
320
321         if (filterExpression[tagNameLength] == ':') {
322                 pri = filter_char_to_pri(filterExpression[tagNameLength+1]);
323
324                 if (pri == DLOG_UNKNOWN)
325                         goto error;
326         }
327
328         if (0 == strncmp("*", filterExpression, tagNameLength)) {
329                 /* This filter expression refers to the global filter
330                  * The default level for this is DEBUG if the priority
331                  * is unspecified
332                  */
333                 if (pri == DLOG_DEFAULT)
334                         pri = DLOG_DEBUG;
335
336                 p_format->global_pri = pri;
337         } else {
338                 /* for filter expressions that don't refer to the global
339                  * filter, the default is verbose if the priority is unspecified
340                  */
341                 if (pri == DLOG_DEFAULT)
342                         pri = DLOG_VERBOSE;
343
344                 char *tagName;
345                 tagName = strndup(filterExpression, tagNameLength);
346
347                 FilterInfo *p_fi = filterinfo_new(tagName, pri);
348                 free(tagName);
349
350                 p_fi->p_next = p_format->filters;
351                 p_format->filters = p_fi;
352         }
353
354         return 0;
355 error:
356         return -1;
357 }
358
359 /**
360  * @brief Add filter string
361  * @details Adds multiple tag/priority filtering rule from a string
362  * @param[in] p_format The log format to add the filter rules to
363  * @param[in] filterstring A filter string containing multiple filter rules delimited by spaces, tabs or commas
364  * @return 0 on success, else -1
365  * @remarks Assumes single threaded execution
366  */
367 int log_add_filter_string(log_format *p_format,
368                 const char *filterString)
369 {
370         char *filterStringCopy = strdup(filterString);
371         char *p_cur = filterStringCopy;
372         char *p_ret;
373         int err;
374
375         while (NULL != (p_ret = strsep(&p_cur, " \t,"))) {
376                 /* ignore whitespace-only entries */
377                 if (p_ret[0] != '\0') {
378                         err = log_add_filter_rule(p_format, p_ret);
379
380                         if (err < 0)
381                                 goto error;
382                 }
383         }
384
385         free(filterStringCopy);
386         return 0;
387 error:
388         free(filterStringCopy);
389         return -1;
390 }
391
392 /**
393  * @brief Preprocess a log buffer for printing
394  * @details Converts a log entry into a printable format
395  * @param[in] entry_raw The raw entry to convert
396  * @param[out] entry The entry to fill
397  * @return 0 on success, -1 on failure
398  */
399 int log_process_log_buffer(struct logger_entry *entry_raw, log_entry *entry)
400 {
401         //TODO: remove and make log_format_log_line just use raw entry directly
402         int i, start = -1, end = -1;
403
404         if (entry_raw->len < 3) {
405                 fprintf(stderr, "Entry too small\n");
406                 return -1;
407         }
408
409         entry->tv_sec = entry_raw->sec;
410         entry->tv_nsec = entry_raw->nsec;
411         entry->pid = entry_raw->pid;
412         entry->tid = entry_raw->tid;
413
414         entry->priority = entry_raw->msg[0];
415         if (entry->priority < 0 || entry->priority > DLOG_SILENT) {
416                 fprintf(stderr, "Wrong priority message, %d but should be <%d\n", entry->priority, DLOG_SILENT);
417                 return -1;
418         }
419
420         entry->tag = entry_raw->msg + 1;
421         if (!strlen(entry->tag)) {
422                 fprintf(stderr, "No tag message\n");
423                 return -1;
424         }
425
426         for (i = 0; i < entry_raw->len; i++) {
427                 if (entry_raw->msg[i] == '\0') {
428                         if (start == -1) {
429                                 start = i + 1;
430                         } else {
431                                 end = i;
432                                 break;
433                         }
434                 }
435         }
436         if (start == -1) {
437                 fprintf(stderr, "Malformed log message\n");
438                 return -1;
439         }
440         if (end == -1) {
441                 end = entry_raw->len - 1;
442                 entry_raw->msg[end] = '\0';
443         }
444
445         entry->message = entry_raw->msg + start;
446         entry->messageLen = end - start;
447
448         return 0;
449 }
450
451 /**
452  * @brief Format log line
453  * @details Formats a log entry for direct printing
454  * @param[in] p_format The log format to use
455  * @param[out] defaultBuffer The buffer to write into, if possible
456  * @param[in] defaultBufferSize The size of the default buffer
457  * @param[in] entry The entry to format
458  * @param[out] p_outLength The length of the output
459  * @return The resulting buffer (defaultBuffer if possible, else a malloc'd one)
460  * @remarks If the returned value is not defaultBuffer, it has to be free'd
461  */
462 char *log_format_log_line(
463                 log_format *p_format,
464                 char *defaultBuffer,
465                 size_t defaultBufferSize,
466                 const log_entry *entry,
467                 size_t *p_outLength)
468 {
469 #if defined(HAVE_LOCALTIME_R)
470         struct tm tmBuf;
471 #endif
472         struct tm* ptm;
473         char timeBuf[32], tzBuf[16];
474         char prefixBuf[128], suffixBuf[128];
475         char priChar;
476         int prefixSuffixIsHeaderFooter = 0;
477         char * ret = NULL;
478
479         priChar = filter_pri_to_char(entry->priority);
480
481         /*
482          * Get the current date/time in pretty form
483          *
484          * It's often useful when examining a log with "less" to jump to
485          * a specific point in the file by searching for the date/time stamp.
486          * For this reason it's very annoying to have regexp meta characters
487          * in the time stamp.  Don't use forward slashes, parenthesis,
488          * brackets, asterisks, or other special chars here.
489          */
490 #if defined(HAVE_LOCALTIME_R)
491         ptm = localtime_r(&(entry->tv_sec), &tmBuf);
492 #else
493         ptm = localtime(&(entry->tv_sec));
494 #endif
495         strftime(timeBuf, sizeof(timeBuf), "%m-%d %H:%M:%S", ptm);
496         strftime(tzBuf, sizeof(tzBuf), "%z", ptm);
497
498         /*
499          * Construct a buffer containing the log header and log message.
500          */
501         size_t prefixLen, suffixLen;
502
503         switch (p_format->format) {
504         case FORMAT_TAG:
505                 prefixLen = snprintf(prefixBuf, sizeof(prefixBuf),
506                                 "%c/%-8s: ", priChar, entry->tag);
507                 strncpy(suffixBuf, "\n", 2); suffixLen = 1;
508                 break;
509         case FORMAT_PROCESS:
510                 prefixLen = snprintf(prefixBuf, sizeof(prefixBuf),
511                                 "%c(%5d) ", priChar, (int)entry->pid);
512                 suffixLen = snprintf(suffixBuf, sizeof(suffixBuf),
513                                 "  (%s)\n", entry->tag);
514                 break;
515         case FORMAT_THREAD:
516                 prefixLen = snprintf(prefixBuf, sizeof(prefixBuf),
517                                 "%c(P%5d, T%5d) ", priChar, (int)entry->pid, (int)entry->tid);
518                 strncpy(suffixBuf, "\n", 2);
519                 suffixLen = 1;
520                 break;
521         case FORMAT_RAW:
522                 prefixBuf[0] = 0;
523                 prefixLen = 0;
524                 strncpy(suffixBuf, "\n", 2);
525                 suffixLen = 1;
526                 break;
527         case FORMAT_TIME:
528                 prefixLen = snprintf(prefixBuf, sizeof(prefixBuf),
529                                 "%s.%03ld%s %c/%-8s(%5d): ", timeBuf, entry->tv_nsec / 1000000,
530                                 tzBuf, priChar, entry->tag, (int)entry->pid);
531                 strncpy(suffixBuf, "\n", 2);
532                 suffixLen = 1;
533                 break;
534         case FORMAT_THREADTIME:
535                 prefixLen = snprintf(prefixBuf, sizeof(prefixBuf),
536                                 "%s.%03ld%s %c/%-8s(P%5d, T%5d): ",
537                                 timeBuf, entry->tv_nsec / 1000000,
538                                 tzBuf, priChar, entry->tag, (int)entry->pid, (int)entry->tid);
539                 strncpy(suffixBuf, "\n", 2);
540                 suffixLen = 1;
541                 break;
542         case FORMAT_KERNELTIME:
543                 prefixLen = snprintf(prefixBuf, sizeof(prefixBuf),
544                                 "%5lu.%03ld %c/%-8s(P%5d, T%5d): ",
545                                 entry->tv_sec, entry->tv_nsec / 1000000,
546                                 priChar, entry->tag, (int)entry->pid, (int)entry->tid);
547                 strncpy(suffixBuf, "\n", 2);
548                 suffixLen = 1;
549                 break;
550         case FORMAT_LONG:
551                 prefixLen = snprintf(prefixBuf, sizeof(prefixBuf),
552                                 "[ %s.%03ld %c/%-8s P%5d, T%5d]\n",
553                                 timeBuf, entry->tv_nsec / 1000000, priChar, entry->tag,
554                                 (int)entry->pid, (int)entry->tid);
555                 strncpy(suffixBuf, "\n\n", 3);
556                 suffixLen = 2;
557                 prefixSuffixIsHeaderFooter = 1;
558                 break;
559         case FORMAT_BRIEF:
560         default:
561                 prefixLen = snprintf(prefixBuf, sizeof(prefixBuf),
562                                 "%c/%-8s(%5d): ", priChar, entry->tag, (int)entry->pid);
563                 strncpy(suffixBuf, "\n", 2);
564                 suffixLen = 1;
565                 break;
566         }
567         /* snprintf has a weird return value.   It returns what would have been
568          * written given a large enough buffer.  In the case that the prefix is
569          * longer then our buffer(128), it messes up the calculations below
570          * possibly causing heap corruption.  To avoid this we double check and
571          * set the length at the maximum (size minus null byte)
572          */
573         if (prefixLen >= sizeof(prefixBuf))
574                 prefixLen = sizeof(prefixBuf) - 1;
575         if (suffixLen >= sizeof(suffixBuf))
576                 suffixLen = sizeof(suffixBuf) - 1;
577
578         /* the following code is tragically unreadable */
579
580         size_t numLines;
581         char *p;
582         size_t bufferSize;
583         const char *pm;
584
585         if (prefixSuffixIsHeaderFooter) {
586                 /* we're just wrapping message with a header/footer */
587                 numLines = 1;
588         } else {
589                 pm = entry->message;
590                 numLines = 0;
591
592                 /* The line-end finding here must match the line-end finding
593                  * in for ( ... numLines...) loop below
594                  */
595                 while (pm < (entry->message + entry->messageLen)) {
596                         if (*pm++ == '\n') numLines++;
597                 }
598                 /* plus one line for anything not newline-terminated at the end */
599                 if (pm > entry->message && *(pm-1) != '\n') numLines++;
600         }
601
602         /* this is an upper bound--newlines in message may be counted
603          * extraneously
604          */
605         bufferSize = (numLines * (prefixLen + suffixLen)) + entry->messageLen + 1;
606
607         if (defaultBufferSize >= bufferSize) {
608                 ret = defaultBuffer;
609         } else {
610                 ret = (char *)malloc(bufferSize);
611
612                 if (ret == NULL)
613                         return ret;
614         }
615
616         ret[0] = '\0';       /* to start strcat off */
617
618         p = ret;
619         pm = entry->message;
620
621         if (prefixSuffixIsHeaderFooter) {
622                 strncat(p, prefixBuf, prefixLen);
623                 p += prefixLen;
624                 strncat(p, entry->message, entry->messageLen);
625                 p += entry->messageLen;
626                 strncat(p, suffixBuf, suffixLen);
627                 p += suffixLen;
628         } else {
629                 while (pm < (entry->message + entry->messageLen)) {
630                         const char *lineStart;
631                         size_t lineLen;
632
633                         lineStart = pm;
634
635                         /* Find the next end-of-line in message */
636                         while (pm < (entry->message + entry->messageLen)
637                                         && *pm != '\n') pm++;
638                         lineLen = pm - lineStart;
639
640                         strncat(p, prefixBuf, prefixLen);
641                         p += prefixLen;
642                         strncat(p, lineStart, lineLen);
643                         p += lineLen;
644                         strncat(p, suffixBuf, suffixLen);
645                         p += suffixLen;
646
647                         if (*pm == '\n')
648                                 pm++;
649                 }
650         }
651
652         if (p_outLength != NULL)
653                 *p_outLength = p - ret;
654
655         return ret;
656 }
657
658 /**
659  * @brief Print log line
660  * @details Prints the given log entry to the supplied file descriptor
661  * @param[in] p_format The format to use
662  * @param[in] fd The file descriptor to write to
663  * @param[in] entry The entry to print
664  * @return Bytes written
665  */
666 int log_print_log_line(
667                 log_format *p_format,
668                 int fd,
669                 const log_entry *entry)
670 {
671         int ret;
672         char defaultBuffer[512];
673         char *outBuffer = NULL;
674         size_t totalLen;
675
676         outBuffer = log_format_log_line(p_format,
677                         defaultBuffer, sizeof(defaultBuffer), entry, &totalLen);
678
679         if (!outBuffer)
680                 return -1;
681
682         do {
683                 ret = write(fd, outBuffer, totalLen);
684         } while (ret < 0 && errno == EINTR);
685
686         if (ret < 0) {
687                 _E("+++ LOG: write failed (errno=%d)\n", errno);
688                 ret = 0;
689                 goto done;
690         }
691
692         if (((size_t)ret) < totalLen) {
693                 _E("+++ LOG: write partial (%d of %d)\n", ret,
694                                 (int)totalLen);
695                 goto done;
696         }
697
698 done:
699         if (outBuffer != defaultBuffer)
700                 free(outBuffer);
701
702         return ret;
703 }