modified for systemd journal support
[framework/system/dlog.git] / logutil.c
1 /*
2  * Copyright (C) 2007 The Android Open Source Project
3  *
4  * Licensed under the Apache License, Version 2.0 (the "License");
5  * you may not use this file except in compliance with the License.
6  * You may obtain a copy of the License at
7  *
8  *      http://www.apache.org/licenses/LICENSE-2.0
9  *
10  * Unless required by applicable law or agreed to in writing, software
11  * distributed under the License is distributed on an "AS IS" BASIS,
12  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13  * See the License for the specific language governing permissions and
14  * limitations under the License.
15  */
16
17
18 #include <stdio.h>
19 #include <stdlib.h>
20 #include <stdbool.h>
21 #include <stdarg.h>
22 #include <string.h>
23 #include <unistd.h>
24 #include <fcntl.h>
25 #include <time.h>
26 #include <sys/time.h>
27 #include <ctype.h>
28 #include <errno.h>
29 #include <assert.h>
30 #include <sys/stat.h>
31 #include <arpa/inet.h>
32
33
34 #include <logger.h>
35 #include <logprint.h>
36
37 #define DEFAULT_LOG_ROTATE_SIZE_KBYTES 16
38 #define DEFAULT_MAX_ROTATED_LOGS 4
39
40 #define LOG_FILE_DIR    "/dev/log_"
41
42 static log_format* g_logformat;
43 static bool g_nonblock = false;
44 static int g_tail_lines = 0;
45
46 static const char * g_output_filename = NULL;
47 static int g_log_rotate_size_kbytes = 0;                   // 0 means "no log rotation"
48 static int g_max_rotated_logs = DEFAULT_MAX_ROTATED_LOGS; // 0 means "unbounded"
49 static int g_outfd = -1;
50 static off_t g_out_byte_count = 0;
51 static int g_dev_count = 0;
52
53 struct queued_entry_t {
54         union {
55                 unsigned char buf[LOGGER_ENTRY_MAX_LEN + 1] __attribute__((aligned(4)));
56                 struct logger_entry entry __attribute__((aligned(4)));
57         };
58         struct queued_entry_t* next;
59 };
60
61 static int cmp(struct queued_entry_t* a, struct queued_entry_t* b)
62 {
63         int n = a->entry.sec - b->entry.sec;
64         if (n != 0)
65         {
66                 return n;
67         }
68         return a->entry.nsec - b->entry.nsec;
69 }
70
71
72 struct log_device_t {
73         char* device;
74         int fd;
75         bool printed;
76         struct queued_entry_t* queue;
77         struct log_device_t* next;
78 };
79
80 static void enqueue(struct log_device_t* device, struct queued_entry_t* entry)
81 {
82         if( device->queue == NULL)
83         {
84                 device->queue = entry;
85         }
86         else
87         {
88                 struct queued_entry_t** e = &device->queue;
89                 while(*e && cmp(entry, *e) >= 0 )
90                 {
91                         e = &((*e)->next);
92                 }
93                 entry->next = *e;
94                 *e = entry;
95     }
96 }
97
98 static int open_logfile (const char *pathname)
99 {
100     return open(pathname, O_WRONLY | O_APPEND | O_CREAT, S_IRUSR | S_IWUSR | S_IRGRP | S_IWGRP | S_IROTH);
101 }
102
103 static void rotate_logs()
104 {
105     int err;
106         int i;
107         char file0[256]={0};
108         char file1[256]={0};
109
110     // Can't rotate logs if we're not outputting to a file
111     if (g_output_filename == NULL) {
112         return;
113     }
114
115     close(g_outfd);
116
117     for (i = g_max_rotated_logs ; i > 0 ; i--)
118         {
119                 snprintf(file1, 255, "%s.%d", g_output_filename, i);
120
121                 if (i - 1 == 0) {
122                         snprintf(file0, 255, "%s", g_output_filename);
123                 } else {
124                         snprintf(file0, 255, "%s.%d", g_output_filename, i - 1);
125                 }
126
127                 err = rename (file0, file1);
128
129                 if (err < 0 && errno != ENOENT) {
130                         perror("while rotating log files");
131                 }
132     }
133
134     g_outfd = open_logfile (g_output_filename);
135
136     if (g_outfd < 0) {
137         perror ("couldn't open output file");
138         exit(-1);
139     }
140
141     g_out_byte_count = 0;
142
143 }
144
145
146 static void processBuffer(struct log_device_t* dev, struct logger_entry *buf)
147 {
148         int bytes_written = 0;
149         int err;
150         log_entry entry;
151         char mgs_buf[1024];
152
153         err = log_process_log_buffer(buf, &entry);
154
155         if (err < 0) {
156                 goto error;
157         }
158
159         if (log_should_print_line(g_logformat, entry.tag, entry.priority)) {
160                 if (false && g_dev_count > 1) {
161                         // FIXME
162                         mgs_buf[0] = dev->device[0];
163                         mgs_buf[1] = ' ';
164                         bytes_written = write(g_outfd, mgs_buf, 2);
165                         if (bytes_written < 0)
166                         {
167                                 perror("output error");
168                                 exit(-1);
169                         }
170                 }
171
172                 bytes_written = log_print_log_line(g_logformat, g_outfd, &entry);
173
174                 if (bytes_written < 0)
175                 {
176                         perror("output error");
177                         exit(-1);
178                 }
179         }
180
181         g_out_byte_count += bytes_written;
182
183     if (g_log_rotate_size_kbytes > 0 && (g_out_byte_count / 1024) >= g_log_rotate_size_kbytes)
184         {
185                 rotate_logs();
186         }
187
188 error:
189         //fprintf (stderr, "Error processing record\n");
190         return;
191 }
192
193 static void chooseFirst(struct log_device_t* dev, struct log_device_t** firstdev)
194 {
195         for (*firstdev = NULL; dev != NULL; dev = dev->next) {
196                 if (dev->queue != NULL && (*firstdev == NULL || cmp(dev->queue, (*firstdev)->queue) < 0))
197                 {
198                         *firstdev = dev;
199                 }
200         }
201 }
202
203 static void maybePrintStart(struct log_device_t* dev) {
204         if (!dev->printed) {
205                 dev->printed = true;
206                 if (g_dev_count > 1 ) {
207                         char buf[1024];
208                         snprintf(buf, sizeof(buf), "--------- beginning of %s\n", dev->device);
209                         if (write(g_outfd, buf, strlen(buf)) < 0) {
210                                 perror("output error");
211                                 exit(-1);
212                         }
213                 }
214         }
215 }
216
217 static void skipNextEntry(struct log_device_t* dev) {
218         maybePrintStart(dev);
219         struct queued_entry_t* entry = dev->queue;
220         dev->queue = entry->next;
221         free(entry);
222 }
223
224 static void printNextEntry(struct log_device_t* dev)
225 {
226         maybePrintStart(dev);
227         processBuffer(dev, &dev->queue->entry);
228         skipNextEntry(dev);
229 }
230
231
232 static void read_log_lines(struct log_device_t* devices)
233 {
234         struct log_device_t* dev;
235         int max = 0;
236         int ret;
237         int queued_lines = 0;
238         bool sleep = false; // for exit immediately when log buffer is empty and g_nonblock value is true.
239
240         int result;
241         fd_set readset;
242
243         for (dev=devices; dev; dev = dev->next) {
244                 if (dev->fd > max) {
245                         max = dev->fd;
246                 }
247         }
248
249         while (1) {
250                 do {
251                         struct timeval timeout = { 0, 5000 /* 5ms */ }; // If we oversleep it's ok, i.e. ignore EINTR.
252                         FD_ZERO(&readset);
253                         for (dev=devices; dev; dev = dev->next) {
254                                 FD_SET(dev->fd, &readset);
255                         }
256                         result = select(max + 1, &readset, NULL, NULL, sleep ? NULL : &timeout);
257                 } while (result == -1 && errno == EINTR);
258
259         if (result >= 0) {
260             for (dev=devices; dev; dev = dev->next) {
261                 if (FD_ISSET(dev->fd, &readset)) {
262                     struct queued_entry_t* entry = (struct queued_entry_t *)malloc(sizeof( struct queued_entry_t));
263                                         if (entry == NULL) {
264                                                 fprintf(stderr,"Can't malloc queued_entry\n");
265                                                 exit(-1);
266                                         }
267                                         entry->next = NULL;
268
269                     /* NOTE: driver guarantees we read exactly one full entry */
270                     ret = read(dev->fd, entry->buf, LOGGER_ENTRY_MAX_LEN);
271                     if (ret < 0) {
272                         if (errno == EINTR) {
273                             free(entry);
274                             goto next;
275                         }
276                         if (errno == EAGAIN) {
277                             free(entry);
278                             break;
279                         }
280                         perror("dlogutil read");
281                         exit(EXIT_FAILURE);
282                     }
283                     else if (!ret) {
284                         fprintf(stderr, "read: Unexpected EOF!\n");
285                         exit(EXIT_FAILURE);
286                     }
287
288                     entry->entry.msg[entry->entry.len] = '\0';
289
290                     enqueue(dev, entry);
291                     ++queued_lines;
292                 }
293             }
294
295             if (result == 0) {
296                 // we did our short timeout trick and there's nothing new
297                 // print everything we have and wait for more data
298                 sleep = true;
299                 while (true) {
300                     chooseFirst(devices, &dev);
301                     if (dev == NULL) {
302                         break;
303                     }
304                     if (g_tail_lines == 0 || queued_lines <= g_tail_lines) {
305                         printNextEntry(dev);
306                     } else {
307                         skipNextEntry(dev);
308                     }
309                     --queued_lines;
310                 }
311
312                 // the caller requested to just dump the log and exit
313                 if (g_nonblock) {
314                     exit(0);
315                 }
316             } else {
317                 // print all that aren't the last in their list
318                 sleep = false;
319                 while (g_tail_lines == 0 || queued_lines > g_tail_lines) {
320                     chooseFirst(devices, &dev);
321                     if (dev == NULL || dev->queue->next == NULL) {
322                         break;
323                     }
324                     if (g_tail_lines == 0) {
325                         printNextEntry(dev);
326                     } else {
327                         skipNextEntry(dev);
328                     }
329                     --queued_lines;
330                 }
331             }
332         }
333 next:
334         ;
335     }
336 }
337
338
339 static int clear_log(int logfd)
340 {
341     return ioctl(logfd, LOGGER_FLUSH_LOG);
342 }
343
344 /* returns the total size of the log's ring buffer */
345 static int get_log_size(int logfd)
346 {
347     return ioctl(logfd, LOGGER_GET_LOG_BUF_SIZE);
348 }
349
350 /* returns the readable size of the log's ring buffer (that is, amount of the log consumed) */
351 static int get_log_readable_size(int logfd)
352 {
353     return ioctl(logfd, LOGGER_GET_LOG_LEN);
354 }
355
356 static void setup_output()
357 {
358
359         if (g_output_filename == NULL) {
360                 g_outfd = STDOUT_FILENO;
361
362         } else {
363                 struct stat statbuf;
364
365                 g_outfd = open_logfile (g_output_filename);
366
367                 if (g_outfd < 0) {
368                         perror ("couldn't open output file");
369                         exit(-1);
370                 }
371                 if (fstat(g_outfd, &statbuf) == -1)
372                         g_out_byte_count = 0;
373                 else
374                         g_out_byte_count = statbuf.st_size;
375         }
376 }
377
378 static int set_log_format(const char * formatString)
379 {
380         static log_print_format format;
381
382         format = log_format_from_string(formatString);
383
384         if (format == FORMAT_OFF) {
385                 // FORMAT_OFF means invalid string
386                 return -1;
387         }
388
389         log_set_print_format(g_logformat, format);
390
391         return 0;
392 }
393
394 static void show_help(const char *cmd)
395 {
396     fprintf(stderr,"Usage: %s [options] [filterspecs]\n", cmd);
397
398     fprintf(stderr, "options include:\n"
399                     "  -s              Set default filter to silent.\n"
400                     "                  Like specifying filterspec '*:s'\n"
401                     "  -f <filename>   Log to file. Default to stdout\n"
402                     "  -r [<kbytes>]   Rotate log every kbytes. (16 if unspecified). Requires -f\n"
403                     "  -n <count>      Sets max number of rotated logs to <count>, default 4\n"
404                     "  -v <format>     Sets the log print format, where <format> is one of:\n\n"
405                     "                  brief(by default) process tag thread raw time threadtime long\n\n"
406                     "  -c              clear (flush) the entire log and exit, conflicts with '-g'\n"
407                     "  -d              dump the log and then exit (don't block)\n"
408                     "  -t <count>      print only the most recent <count> lines (implies -d)\n"
409                     "  -g              get the size of the log's ring buffer and exit, conflicts with '-c'\n"
410                     "  -b <buffer>     request alternate ring buffer\n"
411                     "                  ('main' (default), 'radio', 'system')");
412
413
414     fprintf(stderr,"\nfilterspecs are a series of \n"
415                    "  <tag>[:priority]\n\n"
416                    "where <tag> is a log component tag (or * for all) and priority is:\n"
417                    "  V    Verbose\n"
418                    "  D    Debug\n"
419                    "  I    Info\n"
420                    "  W    Warn\n"
421                    "  E    Error\n"
422                    "  F    Fatal\n"
423                    "  S    Silent (supress all output)\n"
424                    "\n'*' means '*:D' and <tag> by itself means <tag>:V\n"
425                    "If no filterspec is found, filter defaults to '*:I'\n\n");
426 }
427
428
429 /*
430  * free one log_device_t and it doesn't take care of chain so it
431  * may break the chain list
432  */
433 static void log_devices_free(struct log_device_t *dev)
434 {
435         if (!dev)
436                 return;
437
438         if (dev->device)
439                 free(dev->device);
440
441         if (dev->queue) {
442                 while (dev->queue->next) {
443                         struct queued_entry_t *tmp = dev->queue->next;
444                         dev->queue->next = tmp->next;
445                         free(tmp);
446                 }
447                 free(dev->queue);
448         }
449
450         free(dev);
451         dev = NULL;
452 }
453
454
455 /*
456  * free all the nodes after the "dev" and includes itself
457  */
458 static void log_devices_chain_free(struct log_device_t *dev)
459 {
460         if (!dev)
461                 return;
462
463         while (dev->next) {
464                 struct log_device_t *tmp = dev->next;
465                 dev->next = tmp->next;
466                 log_devices_free(tmp);
467         }
468
469         log_devices_free(dev);
470         dev = NULL;
471 }
472
473
474 /*
475  * create a new log_device_t instance but don't care about
476  * the device node accessable or not
477  */
478 static struct log_device_t *log_devices_new(const char *path)
479 {
480         struct log_device_t *new;
481
482         if (!path || strlen(path) <= 0)
483                 return NULL;
484
485         new = malloc(sizeof(*new));
486         if (!new) {
487                 fprintf(stderr, "out of memory\n");
488                 return NULL;
489         }
490
491         new->device = strdup(path);
492         new->fd = -1;
493         new->printed = false;
494         new->queue = NULL;
495         new->next = NULL;
496
497         return new;
498 }
499
500
501 /*
502  * add a new device to the tail of chain
503  */
504 static int log_devices_add_to_tail(struct log_device_t *devices, struct log_device_t *new)
505 {
506         struct log_device_t *tail = devices;
507
508         if (!devices || !new)
509                 return -1;
510
511         while (tail->next)
512                 tail = tail->next;
513
514         tail->next = new;
515         g_dev_count++;
516
517         return 0;
518 }
519
520 int main(int argc, char **argv)
521 {
522     int err;
523     int has_set_log_format = 0;
524     int is_clear_log = 0;
525     int getLogSize = 0;
526     int mode = O_RDONLY;
527         int i;
528 //    const char *forceFilters = NULL;
529         struct log_device_t* devices = NULL;
530         struct log_device_t* dev;
531
532     g_logformat = (log_format *)log_format_new();
533
534     if (argc == 2 && 0 == strcmp(argv[1], "--test")) {
535         logprint_run_tests();
536         exit(0);
537     }
538
539     if (argc == 2 && 0 == strcmp(argv[1], "--help")) {
540         show_help(argv[0]);
541         exit(0);
542     }
543
544     for (;;) {
545         int ret;
546
547         ret = getopt(argc, argv, "cdt:gsf:r:n:v:b:D");
548
549         if (ret < 0) {
550             break;
551         }
552
553         switch(ret) {
554             case 's':
555                 // default to all silent
556                 log_add_filter_rule(g_logformat, "*:s");
557             break;
558
559             case 'c':
560                 is_clear_log = 1;
561                 mode = O_WRONLY;
562             break;
563
564             case 'd':
565                 g_nonblock = true;
566             break;
567
568             case 't':
569                 g_nonblock = true;
570                 g_tail_lines = atoi(optarg);
571             break;
572
573
574             case 'g':
575                 getLogSize = 1;
576             break;
577
578                         case 'b': {
579                                                   char *buf;
580                                                   if (asprintf(&buf, LOG_FILE_DIR "%s", optarg) == -1) {
581                                                           asprintf(stderr,"Can't malloc LOG_FILE_DIR\n");
582                                                           exit(-1);
583                                                   }
584
585                                                   dev = log_devices_new(buf);
586                 if (devices) {
587                                         if (log_devices_add_to_tail(devices, dev)) {
588                                                 fprintf(stderr, "Open log device %s failed\n", buf);
589                                                 exit(-1);
590                                         }
591                 } else {
592                                         devices = dev;
593                                         g_dev_count = 1;
594                 }
595             }
596             break;
597
598             case 'f':
599                 // redirect output to a file
600
601                 g_output_filename = optarg;
602
603             break;
604
605             case 'r':
606 //                if (optarg == NULL) {
607 //                                      fprintf(stderr,"optarg == null\n");
608  //                  g_log_rotate_size_kbytes = DEFAULT_LOG_ROTATE_SIZE_KBYTES;
609  //              } else {
610                     //long logRotateSize;
611                     //char *lastDigit;
612
613                     if (!isdigit(optarg[0])) {
614                         fprintf(stderr,"Invalid parameter to -r\n");
615                         show_help(argv[0]);
616                         exit(-1);
617                     }
618                     g_log_rotate_size_kbytes = atoi(optarg);
619    //             }
620             break;
621
622             case 'n':
623                 if (!isdigit(optarg[0])) {
624                     fprintf(stderr,"Invalid parameter to -r\n");
625                     show_help(argv[0]);
626                     exit(-1);
627                 }
628
629                 g_max_rotated_logs = atoi(optarg);
630             break;
631
632             case 'v':
633                 err = set_log_format (optarg);
634                 if (err < 0) {
635                     fprintf(stderr,"Invalid parameter to -v\n");
636                     show_help(argv[0]);
637                     exit(-1);
638                 }
639
640                 has_set_log_format = 1;
641             break;
642
643                         default:
644                                 fprintf(stderr,"Unrecognized Option\n");
645                                 show_help(argv[0]);
646                                 exit(-1);
647                         break;
648                 }
649         }
650
651         /* get log size conflicts with write mode */
652         if (getLogSize && mode != O_RDONLY) {
653                 show_help(argv[0]);
654                 exit(-1);
655         }
656
657         if (!devices) {
658                 devices = log_devices_new("/dev/"LOGGER_LOG_MAIN);
659                 if (devices == NULL) {
660                         fprintf(stderr,"Can't add log device: %s\n", LOGGER_LOG_MAIN);
661                         exit(-1);
662                 }
663         g_dev_count = 1;
664
665         int accessmode =
666                   (mode == O_RDONLY) ? R_OK : 0
667                 | (mode == O_WRONLY) ? W_OK : 0;
668
669         // only add this if it's available
670         if (0 == access("/dev/"LOGGER_LOG_SYSTEM, accessmode)) {
671                 if (log_devices_add_to_tail(devices, log_devices_new("/dev/"LOGGER_LOG_SYSTEM))) {
672                         fprintf(stderr,"Can't add log device: %s\n", LOGGER_LOG_SYSTEM);
673                         exit(-1);
674                 }
675         }
676
677         if (0 == access("/dev/"LOGGER_LOG_APPS, accessmode)) {
678                 if (log_devices_add_to_tail(devices, log_devices_new("/dev/"LOGGER_LOG_APPS))) {
679                         fprintf(stderr,"Can't add log device: %s\n", LOGGER_LOG_APPS);
680                         exit(-1);
681                 }
682         }
683 /*
684         // only add this if it's available
685         int fd;
686         if ((fd = open("/dev/"LOGGER_LOG_SYSTEM, mode)) != -1) {
687                 devices->next = (struct log_device_t *)malloc( sizeof(struct log_device_t));
688                 devices->next->device = strdup("/dev/"LOGGER_LOG_SYSTEM);
689                 devices->next->fd = -1;
690                 devices->next->printed = false;
691                 devices->next->queue = NULL;
692                 devices->next->next = NULL;
693                 g_dev_count ++;
694
695                 close(fd);
696         }
697 */
698     }
699
700     if (g_log_rotate_size_kbytes != 0 && g_output_filename == NULL)
701         {
702                 fprintf(stderr,"-r requires -f as well\n");
703                 show_help(argv[0]);
704                 exit(-1);
705         }
706
707     setup_output();
708
709
710         if (has_set_log_format == 0) {
711                 err = set_log_format("brief");
712         }
713 /*
714                 const char* logFormat = getenv("DLOG_PRINTF_LOG");
715
716                 if (logFormat != NULL) {
717                         err = set_log_format("brief");
718
719                         if (err < 0) {
720                                 fprintf(stderr, "invalid format in DLOG_PRINTF_LOG '%s'\n", logFormat);
721                         }
722                 }
723         }
724         if (forceFilters) {
725                 err = log_add_filter_string(g_logformat, forceFilters);
726                 if (err < 0) {
727                         fprintf (stderr, "Invalid filter expression in -logcat option\n");
728                         exit(0);
729                 }
730         } else if (argc == optind) {
731         // Add from environment variable
732                 char *env_tags_orig = getenv("DLOG_LOG_TAGS");
733
734                 if (env_tags_orig != NULL) {
735                         err = log_add_filter_string(g_logformat, env_tags_orig);
736
737                         if (err < 0) {
738                                 fprintf(stderr, "Invalid filter expression in DLOG_LOG_TAGS\n");
739                                 show_help(argv[0]);
740                                 exit(-1);
741                         }
742                 }
743         } else {
744         // Add from commandline
745 */
746         fprintf(stderr,"arc = %d, optind = %d ,Kb %d, rotate %d\n", argc, optind,g_log_rotate_size_kbytes,g_max_rotated_logs);
747
748         if(argc == optind )
749         {
750                 // Add from environment variable
751         //char *env_tags_orig = getenv("DLOG_TAGS");
752                 log_add_filter_string(g_logformat, "*:d");
753         }
754         else
755         {
756
757                 for (i = optind ; i < argc ; i++) {
758                         err = log_add_filter_string(g_logformat, argv[i]);
759
760                         if (err < 0) {
761                                 fprintf (stderr, "Invalid filter expression '%s'\n", argv[i]);
762                                 show_help(argv[0]);
763                                 exit(-1);
764                         }
765                 }
766         }
767 /*
768     }
769 */
770     dev = devices;
771     while (dev) {
772         dev->fd = open(dev->device, mode);
773         if (dev->fd < 0) {
774             fprintf(stderr, "Unable to open log device '%s': %s\n",
775                 dev->device, strerror(errno));
776             exit(EXIT_FAILURE);
777         }
778
779         if (is_clear_log) {
780             int ret;
781             ret = clear_log(dev->fd);
782             if (ret) {
783                 perror("ioctl");
784                 exit(EXIT_FAILURE);
785             }
786         }
787
788         if (getLogSize) {
789             int size, readable;
790
791             size = get_log_size(dev->fd);
792             if (size < 0) {
793                 perror("ioctl");
794                 exit(EXIT_FAILURE);
795             }
796
797             readable = get_log_readable_size(dev->fd);
798             if (readable < 0) {
799                 perror("ioctl");
800                 exit(EXIT_FAILURE);
801             }
802
803             printf("%s: ring buffer is %dKb (%dKb consumed), "
804                    "max entry is %db, max payload is %db\n", dev->device,
805                    size / 1024, readable / 1024,
806                    (int) LOGGER_ENTRY_MAX_LEN, (int) LOGGER_ENTRY_MAX_PAYLOAD);
807         }
808
809         dev = dev->next;
810     }
811
812     if (getLogSize) {
813         return 0;
814     }
815
816     if (is_clear_log) {
817         return 0;
818     }
819
820     read_log_lines(devices);
821
822         log_devices_chain_free(devices);
823
824     return 0;
825 }