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);
 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                                         entry->next = NULL;
 264
 265                     /* NOTE: driver guarantees we read exactly one full entry */
 266                     ret = read(dev->fd, entry->buf, LOGGER_ENTRY_MAX_LEN);
 267                     if (ret < 0) {
 268                         if (errno == EINTR) {
 269                             free(entry);
 270                             goto next;
 271                         }
 272                         if (errno == EAGAIN) {
 273                             free(entry);
 274                             break;
 275                         }
 276                         perror("dlogutil read");
 277                         exit(EXIT_FAILURE);
 278                     }
 279                     else if (!ret) {
 280                         fprintf(stderr, "read: Unexpected EOF!\n");
 281                         exit(EXIT_FAILURE);
 282                     }
 283
 284                     entry->entry.msg[entry->entry.len] = '\0';
 285
 286                     enqueue(dev, entry);
 287                     ++queued_lines;
 288                 }
 289             }
 290
 291             if (result == 0) {
 292                 // we did our short timeout trick and there's nothing new
 293                 // print everything we have and wait for more data
 294                 sleep = true;
 295                 while (true) {
 296                     chooseFirst(devices, &dev);
 297                     if (dev == NULL) {
 298                         break;
 299                     }
 300                     if (g_tail_lines == 0 || queued_lines <= g_tail_lines) {
 301                         printNextEntry(dev);
 302                     } else {
 303                         skipNextEntry(dev);
 304                     }
 305                     --queued_lines;
 306                 }
 307
 308                 // the caller requested to just dump the log and exit
 309                 if (g_nonblock) {
 310                     exit(0);
 311                 }
 312             } else {
 313                 // print all that aren't the last in their list
 314                 sleep = false;
 315                 while (g_tail_lines == 0 || queued_lines > g_tail_lines) {
 316                     chooseFirst(devices, &dev);
 317                     if (dev == NULL || dev->queue->next == NULL) {
 318                         break;
 319                     }
 320                     if (g_tail_lines == 0) {
 321                         printNextEntry(dev);
 322                     } else {
 323                         skipNextEntry(dev);
 324                     }
 325                     --queued_lines;
 326                 }
 327             }
 328         }
 329 next:
 330         ;
 331     }
 332 }
 333
 334
 335 static int clear_log(int logfd)
 336 {
 337     return ioctl(logfd, LOGGER_FLUSH_LOG);
 338 }
 339
 340 /* returns the total size of the log's ring buffer */
 341 static int get_log_size(int logfd)
 342 {
 343     return ioctl(logfd, LOGGER_GET_LOG_BUF_SIZE);
 344 }
 345
 346 /* returns the readable size of the log's ring buffer (that is, amount of the log consumed) */
 347 static int get_log_readable_size(int logfd)
 348 {
 349     return ioctl(logfd, LOGGER_GET_LOG_LEN);
 350 }
 351
 352 static void setup_output()
 353 {
 354
 355     if (g_output_filename == NULL) {
 356         g_outfd = STDOUT_FILENO;
 357
 358     } else {
 359         struct stat statbuf;
 360
 361         g_outfd = open_logfile (g_output_filename);
 362
 363         if (g_outfd < 0) {
 364             perror ("couldn't open output file");
 365             exit(-1);
 366         }
 367
 368         fstat(g_outfd, &statbuf);
 369
 370         g_out_byte_count = statbuf.st_size;
 371     }
 372 }
 373
 374 static int set_log_format(const char * formatString)
 375 {
 376         static log_print_format format;
 377
 378         format = log_format_from_string(formatString);
 379
 380         if (format == FORMAT_OFF) {
 381                 // FORMAT_OFF means invalid string
 382                 return -1;
 383         }
 384
 385         log_set_print_format(g_logformat, format);
 386
 387         return 0;
 388 }
 389
 390 static void show_help(const char *cmd)
 391 {
 392     fprintf(stderr,"Usage: %s [options] [filterspecs]\n", cmd);
 393
 394     fprintf(stderr, "options include:\n"
 395                     "  -s              Set default filter to silent.\n"
 396                     "                  Like specifying filterspec '*:s'\n"
 397                     "  -f <filename>   Log to file. Default to stdout\n"
 398                     "  -r [<kbytes>]   Rotate log every kbytes. (16 if unspecified). Requires -f\n"
 399                     "  -n <count>      Sets max number of rotated logs to <count>, default 4\n"
 400                     "  -v <format>     Sets the log print format, where <format> is one of:\n\n"
 401                     "                  brief process tag thread raw time threadtime long\n\n"
 402                     "  -c              clear (flush) the entire log and exit\n"
 403                     "  -d              dump the log and then exit (don't block)\n"
 404                     "  -t <count>      print only the most recent <count> lines (implies -d)\n"
 405                     "  -g              get the size of the log's ring buffer and exit\n"
 406                     "  -b <buffer>     request alternate ring buffer\n"
 407                     "                  ('main' (default), 'radio', 'system')");
 408
 409
 410     fprintf(stderr,"\nfilterspecs are a series of \n"
 411                    "  <tag>[:priority]\n\n"
 412                    "where <tag> is a log component tag (or * for all) and priority is:\n"
 413                    "  V    Verbose\n"
 414                    "  D    Debug\n"
 415                    "  I    Info\n"
 416                    "  W    Warn\n"
 417                    "  E    Error\n"
 418                    "  F    Fatal\n"
 419                    "  S    Silent (supress all output)\n"
 420                    "\n'*' means '*:d' and <tag> by itself means <tag>:v\n"
 421                    "If no filterspec is found, filter defaults to '*:I'\n"
 422                    "\nIf not specified with -v, format is set defaults to \"brief\"\n\n");
 423
 424
 425
 426 }
 427
 428
 429 int main(int argc, char **argv)
 430 {
 431     int err;
 432     int has_set_log_format = 0;
 433     int is_clear_log = 0;
 434     int getLogSize = 0;
 435     int mode = O_RDONLY;
 436         int i;
 437 //    const char *forceFilters = NULL;
 438         struct log_device_t* devices = NULL;
 439         struct log_device_t* dev;
 440
 441     g_logformat = (log_format *)log_format_new();
 442
 443     if (argc == 2 && 0 == strcmp(argv[1], "--test")) {
 444         logprint_run_tests();
 445         exit(0);
 446     }
 447
 448     if (argc == 2 && 0 == strcmp(argv[1], "--help")) {
 449         show_help(argv[0]);
 450         exit(0);
 451     }
 452
 453     for (;;) {
 454         int ret;
 455
 456         ret = getopt(argc, argv, "cdt:gsf:r:n:v:b:D");
 457
 458         if (ret < 0) {
 459             break;
 460         }
 461
 462         switch(ret) {
 463             case 's':
 464                 // default to all silent
 465                 log_add_filter_rule(g_logformat, "*:s");
 466             break;
 467
 468             case 'c':
 469                 is_clear_log = 1;
 470                 mode = O_WRONLY;
 471             break;
 472
 473             case 'd':
 474                 g_nonblock = true;
 475             break;
 476
 477             case 't':
 478                 g_nonblock = true;
 479                 g_tail_lines = atoi(optarg);
 480             break;
 481
 482
 483             case 'g':
 484                 getLogSize = 1;
 485             break;
 486
 487             case 'b': {
 488                 char* buf = (char*) malloc(strlen(LOG_FILE_DIR) + strlen(optarg) + 1);
 489                 strcpy(buf, LOG_FILE_DIR);
 490                 strcat(buf, optarg);
 491 //              snprintf(buf, strlen(LOG_FILE_DIR) + strlen(optarg) + 1, "%s%s", LOG_FILE_DIR, optarg);
 492
 493                 if (devices) {
 494                                         dev = devices;
 495                     while (dev->next) {
 496                                                 dev = dev->next;
 497                                         }
 498                                         dev->next = (struct log_device_t *)malloc( sizeof(struct log_device_t));
 499                                         dev->next->device = buf;
 500                                         dev->next->fd = -1;
 501                                         dev->next->printed = false;
 502                                         dev->next->queue = NULL;
 503                                         dev->next->next = NULL;
 504
 505                 } else {
 506                     devices = (struct log_device_t *)malloc( sizeof(struct log_device_t));
 507                                         devices->device = buf;
 508                                         devices->fd = -1;
 509                                         devices->printed = false;
 510                                         devices->queue = NULL;
 511                                         devices->next = NULL;
 512                 }
 513                 g_dev_count++;
 514             }
 515             break;
 516
 517             case 'f':
 518                 // redirect output to a file
 519
 520                 g_output_filename = optarg;
 521
 522             break;
 523
 524             case 'r':
 525 //                if (optarg == NULL) {
 526 //                                      fprintf(stderr,"optarg == null\n");
 527  //                  g_log_rotate_size_kbytes = DEFAULT_LOG_ROTATE_SIZE_KBYTES;
 528  //              } else {
 529                     //long logRotateSize;
 530                     //char *lastDigit;
 531
 532                     if (!isdigit(optarg[0])) {
 533                         fprintf(stderr,"Invalid parameter to -r\n");
 534                         show_help(argv[0]);
 535                         exit(-1);
 536                     }
 537                     g_log_rotate_size_kbytes = atoi(optarg);
 538    //             }
 539             break;
 540
 541             case 'n':
 542                 if (!isdigit(optarg[0])) {
 543                     fprintf(stderr,"Invalid parameter to -r\n");
 544                     show_help(argv[0]);
 545                     exit(-1);
 546                 }
 547
 548                 g_max_rotated_logs = atoi(optarg);
 549             break;
 550
 551             case 'v':
 552                 err = set_log_format (optarg);
 553                 if (err < 0) {
 554                     fprintf(stderr,"Invalid parameter to -v\n");
 555                     show_help(argv[0]);
 556                     exit(-1);
 557                 }
 558
 559                 has_set_log_format = 1;
 560             break;
 561
 562                         default:
 563                                 fprintf(stderr,"Unrecognized Option\n");
 564                                 show_help(argv[0]);
 565                                 exit(-1);
 566                         break;
 567                 }
 568         }
 569
 570         if (!devices) {
 571         devices = (struct log_device_t *)malloc( sizeof(struct log_device_t));
 572                 devices->device = strdup("/dev/"LOGGER_LOG_MAIN);
 573                 devices->fd = -1;
 574                 devices->printed = false;
 575                 devices->queue = NULL;
 576                 devices->next = NULL;
 577         g_dev_count = 1;
 578
 579
 580         int accessmode =
 581                   (mode & O_RDONLY) ? R_OK : 0
 582                 | (mode & O_WRONLY) ? W_OK : 0;
 583
 584         // only add this if it's available
 585         if (0 == access("/dev/"LOGGER_LOG_SYSTEM, accessmode)) {
 586                 devices->next = (struct log_device_t *)malloc( sizeof(struct log_device_t));
 587                 devices->next->device = strdup("/dev/"LOGGER_LOG_SYSTEM);
 588                 devices->next->fd = -1;
 589                 devices->next->printed = false;
 590                 devices->next->queue = NULL;
 591                 devices->next->next = NULL;
 592                 g_dev_count ++;
 593         }
 594 /*
 595         // only add this if it's available
 596         int fd;
 597         if ((fd = open("/dev/"LOGGER_LOG_SYSTEM, mode)) != -1) {
 598                 devices->next = (struct log_device_t *)malloc( sizeof(struct log_device_t));
 599                 devices->next->device = strdup("/dev/"LOGGER_LOG_SYSTEM);
 600                 devices->next->fd = -1;
 601                 devices->next->printed = false;
 602                 devices->next->queue = NULL;
 603                 devices->next->next = NULL;
 604                 g_dev_count ++;
 605
 606                 close(fd);
 607         }
 608 */
 609     }
 610
 611     if (g_log_rotate_size_kbytes != 0 && g_output_filename == NULL)
 612         {
 613                 fprintf(stderr,"-r requires -f as well\n");
 614                 show_help(argv[0]);
 615                 exit(-1);
 616         }
 617
 618     setup_output();
 619
 620
 621         if (has_set_log_format == 0) {
 622                 err = set_log_format("brief");
 623         }
 624 /*
 625                 const char* logFormat = getenv("DLOG_PRINTF_LOG");
 626
 627                 if (logFormat != NULL) {
 628                         err = set_log_format("brief");
 629
 630                         if (err < 0) {
 631                                 fprintf(stderr, "invalid format in DLOG_PRINTF_LOG '%s'\n", logFormat);
 632                         }
 633                 }
 634         }
 635         if (forceFilters) {
 636                 err = log_add_filter_string(g_logformat, forceFilters);
 637                 if (err < 0) {
 638                         fprintf (stderr, "Invalid filter expression in -logcat option\n");
 639                         exit(0);
 640                 }
 641         } else if (argc == optind) {
 642         // Add from environment variable
 643                 char *env_tags_orig = getenv("DLOG_LOG_TAGS");
 644
 645                 if (env_tags_orig != NULL) {
 646                         err = log_add_filter_string(g_logformat, env_tags_orig);
 647
 648                         if (err < 0) {
 649                                 fprintf(stderr, "Invalid filter expression in DLOG_LOG_TAGS\n");
 650                                 show_help(argv[0]);
 651                                 exit(-1);
 652                         }
 653                 }
 654         } else {
 655         // Add from commandline
 656 */
 657         fprintf(stderr,"arc = %d, optind = %d ,Kb %d, rotate %d\n", argc, optind,g_log_rotate_size_kbytes,g_max_rotated_logs);
 658
 659         if(argc == optind )
 660         {
 661                 // Add from environment variable
 662         //char *env_tags_orig = getenv("DLOG_TAGS");
 663                 log_add_filter_string(g_logformat, "*:d");
 664         }
 665         else
 666         {
 667
 668                 for (i = optind ; i < argc ; i++) {
 669                         err = log_add_filter_string(g_logformat, argv[i]);
 670
 671                         if (err < 0) {
 672                                 fprintf (stderr, "Invalid filter expression '%s'\n", argv[i]);
 673                                 show_help(argv[0]);
 674                                 exit(-1);
 675                         }
 676                 }
 677         }
 678 /*
 679     }
 680 */
 681     dev = devices;
 682     while (dev) {
 683         dev->fd = open(dev->device, mode);
 684         if (dev->fd < 0) {
 685             fprintf(stderr, "Unable to open log device '%s': %s\n",
 686                 dev->device, strerror(errno));
 687             exit(EXIT_FAILURE);
 688         }
 689
 690         if (is_clear_log) {
 691             int ret;
 692             ret = clear_log(dev->fd);
 693             if (ret) {
 694                 perror("ioctl");
 695                 exit(EXIT_FAILURE);
 696             }
 697         }
 698
 699         if (getLogSize) {
 700             int size, readable;
 701
 702             size = get_log_size(dev->fd);
 703             if (size < 0) {
 704                 perror("ioctl");
 705                 exit(EXIT_FAILURE);
 706             }
 707
 708             readable = get_log_readable_size(dev->fd);
 709             if (readable < 0) {
 710                 perror("ioctl");
 711                 exit(EXIT_FAILURE);
 712             }
 713
 714             printf("%s: ring buffer is %dKb (%dKb consumed), "
 715                    "max entry is %db, max payload is %db\n", dev->device,
 716                    size / 1024, readable / 1024,
 717                    (int) LOGGER_ENTRY_MAX_LEN, (int) LOGGER_ENTRY_MAX_PAYLOAD);
 718         }
 719
 720         dev = dev->next;
 721     }
 722
 723     if (getLogSize) {
 724         return 0;
 725     }
 726
 727     if (is_clear_log) {
 728         return 0;
 729     }
 730
 731     read_log_lines(devices);
 732
 733     return 0;
 734 }