logcat_test.cpp revision 7545b471a223a4a222a24b8b1693cc4a69ee3833 
1/*
2 * Copyright (C) 2013-2014 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#include <ctype.h>
18#include <dirent.h>
19#include <signal.h>
20#include <stdio.h>
21#include <stdlib.h>
22#include <string.h>
23#include <sys/types.h>
24#include <sys/wait.h>
25
26#include <gtest/gtest.h>
27#include <log/log.h>
28#include <log/logger.h>
29#include <log/log_read.h>
30
31#define BIG_BUFFER (5 * 1024)
32
33// enhanced version of LOG_FAILURE_RETRY to add support for EAGAIN and
34// non-syscall libs. Since we are only using this in the emergency of
35// a signal to stuff a terminating code into the logs, we will spin rather
36// than try a usleep.
37#define LOG_FAILURE_RETRY(exp) ({  \
38    typeof (exp) _rc;              \
39    do {                           \
40        _rc = (exp);               \
41    } while (((_rc == -1)          \
42           && ((errno == EINTR)    \
43            || (errno == EAGAIN))) \
44          || (_rc == -EINTR)       \
45          || (_rc == -EAGAIN));    \
46    _rc; })
47
48static const char begin[] = "--------- beginning of ";
49
50TEST(logcat, buckets) {
51    FILE *fp;
52
53    ASSERT_TRUE(NULL != (fp = popen(
54      "logcat -b radio -b events -b system -b main -d 2>/dev/null",
55      "r")));
56
57    char buffer[BIG_BUFFER];
58
59    int ids = 0;
60    int count = 0;
61
62    while (fgets(buffer, sizeof(buffer), fp)) {
63        if (!strncmp(begin, buffer, sizeof(begin) - 1)) {
64            while (char *cp = strrchr(buffer, '\n')) {
65                *cp = '\0';
66            }
67            log_id_t id = android_name_to_log_id(buffer + sizeof(begin) - 1);
68            ids |= 1 << id;
69            ++count;
70        }
71    }
72
73    pclose(fp);
74
75    EXPECT_EQ(15, ids);
76
77    EXPECT_EQ(4, count);
78}
79
80TEST(logcat, year) {
81
82    if (android_log_clockid() == CLOCK_MONOTONIC) {
83        fprintf(stderr, "Skipping test, logd is monotonic time\n");
84        return;
85    }
86
87    FILE *fp;
88
89    char needle[32];
90    time_t now;
91    time(&now);
92    struct tm *ptm;
93#if !defined(_WIN32)
94    struct tm tmBuf;
95    ptm = localtime_r(&now, &tmBuf);
96#else
97    ptm = localtime(&&now);
98#endif
99    strftime(needle, sizeof(needle), "[ %Y-", ptm);
100
101    ASSERT_TRUE(NULL != (fp = popen(
102      "logcat -v long -v year -b all -t 3 2>/dev/null",
103      "r")));
104
105    char buffer[BIG_BUFFER];
106
107    int count = 0;
108
109    while (fgets(buffer, sizeof(buffer), fp)) {
110        if (!strncmp(buffer, needle, strlen(needle))) {
111            ++count;
112        }
113    }
114
115    pclose(fp);
116
117    ASSERT_EQ(3, count);
118}
119
120// Return a pointer to each null terminated -v long time field.
121char *fgetLongTime(char *buffer, size_t buflen, FILE *fp) {
122    while (fgets(buffer, buflen, fp)) {
123        char *cp = buffer;
124        if (*cp != '[') {
125            continue;
126        }
127        while (*++cp == ' ') {
128            ;
129        }
130        char *ep = cp;
131        while (isdigit(*ep)) {
132            ++ep;
133        }
134        if ((*ep != '-') && (*ep != '.')) {
135           continue;
136        }
137        // Find PID field
138        while (((ep = strchr(ep, ':'))) && (*++ep != ' ')) {
139            ;
140        }
141        if (!ep) {
142            continue;
143        }
144        ep -= 7;
145        *ep = '\0';
146        return cp;
147    }
148    return NULL;
149}
150
151TEST(logcat, tz) {
152
153    if (android_log_clockid() == CLOCK_MONOTONIC) {
154        fprintf(stderr, "Skipping test, logd is monotonic time\n");
155        return;
156    }
157
158    int tries = 3; // in case run too soon after system start or buffer clear
159    int count;
160
161    do {
162        FILE *fp;
163
164        ASSERT_TRUE(NULL != (fp = popen(
165          "logcat -v long -v America/Los_Angeles -b all -t 3 2>/dev/null",
166          "r")));
167
168        char buffer[BIG_BUFFER];
169
170        count = 0;
171
172        while (fgetLongTime(buffer, sizeof(buffer), fp)) {
173            if (strstr(buffer, " -0700") || strstr(buffer, " -0800")) {
174                ++count;
175            }
176        }
177
178        pclose(fp);
179
180    } while ((count < 3) && --tries && (sleep(1), true));
181
182    ASSERT_EQ(3, count);
183}
184
185TEST(logcat, ntz) {
186    FILE *fp;
187
188    ASSERT_TRUE(NULL != (fp = popen(
189      "logcat -v long -v America/Los_Angeles -v zone -b all -t 3 2>/dev/null",
190      "r")));
191
192    char buffer[BIG_BUFFER];
193
194    int count = 0;
195
196    while (fgetLongTime(buffer, sizeof(buffer), fp)) {
197        if (strstr(buffer, " -0700") || strstr(buffer, " -0800")) {
198            ++count;
199        }
200    }
201
202    pclose(fp);
203
204    ASSERT_EQ(0, count);
205}
206
207void do_tail(int num) {
208    int tries = 3; // in case run too soon after system start or buffer clear
209    int count;
210
211    do {
212        char buffer[BIG_BUFFER];
213
214        snprintf(buffer, sizeof(buffer),
215          "logcat -v long -b radio -b events -b system -b main -t %d 2>/dev/null",
216          num);
217
218        FILE *fp;
219        ASSERT_TRUE(NULL != (fp = popen(buffer, "r")));
220
221        count = 0;
222
223        while (fgetLongTime(buffer, sizeof(buffer), fp)) {
224            ++count;
225        }
226
227        pclose(fp);
228
229    } while ((count < num) && --tries && (sleep(1), true));
230
231    ASSERT_EQ(num, count);
232}
233
234TEST(logcat, tail_3) {
235    do_tail(3);
236}
237
238TEST(logcat, tail_10) {
239    do_tail(10);
240}
241
242TEST(logcat, tail_100) {
243    do_tail(100);
244}
245
246TEST(logcat, tail_1000) {
247    do_tail(1000);
248}
249
250TEST(logcat, tail_time) {
251    FILE *fp;
252
253    ASSERT_TRUE(NULL != (fp = popen("logcat -v long -b all -t 10 2>&1", "r")));
254
255    char buffer[BIG_BUFFER];
256    char *last_timestamp = NULL;
257    char *first_timestamp = NULL;
258    int count = 0;
259
260    char *cp;
261    while ((cp = fgetLongTime(buffer, sizeof(buffer), fp))) {
262        ++count;
263        if (!first_timestamp) {
264            first_timestamp = strdup(cp);
265        }
266        free(last_timestamp);
267        last_timestamp = strdup(cp);
268    }
269    pclose(fp);
270
271    EXPECT_EQ(10, count);
272    EXPECT_TRUE(last_timestamp != NULL);
273    EXPECT_TRUE(first_timestamp != NULL);
274
275    snprintf(buffer, sizeof(buffer), "logcat -v long -b all -t '%s' 2>&1",
276             first_timestamp);
277    ASSERT_TRUE(NULL != (fp = popen(buffer, "r")));
278
279    int second_count = 0;
280    int last_timestamp_count = -1;
281
282    while ((cp = fgetLongTime(buffer, sizeof(buffer), fp))) {
283        ++second_count;
284        if (first_timestamp) {
285            // we can get a transitory *extremely* rare failure if hidden
286            // underneath the time is *exactly* XX-XX XX:XX:XX.XXX000000
287            EXPECT_STREQ(cp, first_timestamp);
288            free(first_timestamp);
289            first_timestamp = NULL;
290        }
291        if (!strcmp(cp, last_timestamp)) {
292            last_timestamp_count = second_count;
293        }
294    }
295    pclose(fp);
296
297    free(last_timestamp);
298    last_timestamp = NULL;
299    free(first_timestamp);
300
301    EXPECT_TRUE(first_timestamp == NULL);
302    EXPECT_LE(count, second_count);
303    EXPECT_LE(count, last_timestamp_count);
304}
305
306TEST(logcat, End_to_End) {
307    pid_t pid = getpid();
308
309    log_time ts(CLOCK_MONOTONIC);
310
311    ASSERT_LT(0, __android_log_btwrite(0, EVENT_TYPE_LONG, &ts, sizeof(ts)));
312
313    FILE *fp;
314    ASSERT_TRUE(NULL != (fp = popen(
315      "logcat -v brief -b events -t 100 2>/dev/null",
316      "r")));
317
318    char buffer[BIG_BUFFER];
319
320    int count = 0;
321
322    while (fgets(buffer, sizeof(buffer), fp)) {
323        int p;
324        unsigned long long t;
325
326        if ((2 != sscanf(buffer, "I/[0]     ( %d): %llu", &p, &t))
327         || (p != pid)) {
328            continue;
329        }
330
331        log_time tx((const char *) &t);
332        if (ts == tx) {
333            ++count;
334        }
335    }
336
337    pclose(fp);
338
339    ASSERT_EQ(1, count);
340}
341
342int get_groups(const char *cmd) {
343    FILE *fp;
344
345    // NB: crash log only available in user space
346    EXPECT_TRUE(NULL != (fp = popen(cmd, "r")));
347
348    if (fp == NULL) {
349        return 0;
350    }
351
352    char buffer[BIG_BUFFER];
353
354    int count = 0;
355
356    while (fgets(buffer, sizeof(buffer), fp)) {
357        int size, consumed, max, payload;
358        char size_mult[3], consumed_mult[3];
359        long full_size, full_consumed;
360
361        size = consumed = max = payload = 0;
362        // NB: crash log can be very small, not hit a Kb of consumed space
363        //     doubly lucky we are not including it.
364        if (6 != sscanf(buffer, "%*s ring buffer is %d%2s (%d%2s consumed),"
365                                " max entry is %db, max payload is %db",
366                                &size, size_mult, &consumed, consumed_mult,
367                                &max, &payload)) {
368            fprintf(stderr, "WARNING: Parse error: %s", buffer);
369            continue;
370        }
371        full_size = size;
372        switch(size_mult[0]) {
373        case 'G':
374            full_size *= 1024;
375            /* FALLTHRU */
376        case 'M':
377            full_size *= 1024;
378            /* FALLTHRU */
379        case 'K':
380            full_size *= 1024;
381            /* FALLTHRU */
382        case 'b':
383            break;
384        }
385        full_consumed = consumed;
386        switch(consumed_mult[0]) {
387        case 'G':
388            full_consumed *= 1024;
389            /* FALLTHRU */
390        case 'M':
391            full_consumed *= 1024;
392            /* FALLTHRU */
393        case 'K':
394            full_consumed *= 1024;
395            /* FALLTHRU */
396        case 'b':
397            break;
398        }
399        EXPECT_GT((full_size * 9) / 4, full_consumed);
400        EXPECT_GT(full_size, max);
401        EXPECT_GT(max, payload);
402
403        if ((((full_size * 9) / 4) >= full_consumed)
404         && (full_size > max)
405         && (max > payload)) {
406            ++count;
407        }
408    }
409
410    pclose(fp);
411
412    return count;
413}
414
415TEST(logcat, get_size) {
416    ASSERT_EQ(4, get_groups(
417      "logcat -v brief -b radio -b events -b system -b main -g 2>/dev/null"));
418}
419
420// duplicate test for get_size, but use comma-separated list of buffers
421TEST(logcat, multiple_buffer) {
422    ASSERT_EQ(4, get_groups(
423      "logcat -v brief -b radio,events,system,main -g 2>/dev/null"));
424}
425
426TEST(logcat, bad_buffer) {
427    ASSERT_EQ(0, get_groups(
428      "logcat -v brief -b radio,events,bogo,system,main -g 2>/dev/null"));
429}
430
431static void caught_blocking(int /*signum*/)
432{
433    unsigned long long v = 0xDEADBEEFA55A0000ULL;
434
435    v += getpid() & 0xFFFF;
436
437    LOG_FAILURE_RETRY(__android_log_btwrite(0, EVENT_TYPE_LONG, &v, sizeof(v)));
438}
439
440TEST(logcat, blocking) {
441    FILE *fp;
442    unsigned long long v = 0xDEADBEEFA55F0000ULL;
443
444    pid_t pid = getpid();
445
446    v += pid & 0xFFFF;
447
448    LOG_FAILURE_RETRY(__android_log_btwrite(0, EVENT_TYPE_LONG, &v, sizeof(v)));
449
450    v &= 0xFFFFFFFFFFFAFFFFULL;
451
452    ASSERT_TRUE(NULL != (fp = popen(
453      "( trap exit HUP QUIT INT PIPE KILL ; sleep 6; echo DONE )&"
454      " logcat -v brief -b events 2>&1",
455      "r")));
456
457    char buffer[BIG_BUFFER];
458
459    int count = 0;
460
461    int signals = 0;
462
463    signal(SIGALRM, caught_blocking);
464    alarm(2);
465    while (fgets(buffer, sizeof(buffer), fp)) {
466
467        if (!strncmp(buffer, "DONE", 4)) {
468            break;
469        }
470
471        ++count;
472
473        int p;
474        unsigned long long l;
475
476        if ((2 != sscanf(buffer, "I/[0] ( %u): %lld", &p, &l))
477         || (p != pid)) {
478            continue;
479        }
480
481        if (l == v) {
482            ++signals;
483            break;
484        }
485    }
486    alarm(0);
487    signal(SIGALRM, SIG_DFL);
488
489    // Generate SIGPIPE
490    fclose(fp);
491    caught_blocking(0);
492
493    pclose(fp);
494
495    EXPECT_LE(2, count);
496
497    EXPECT_EQ(1, signals);
498}
499
500static void caught_blocking_tail(int /*signum*/)
501{
502    unsigned long long v = 0xA55ADEADBEEF0000ULL;
503
504    v += getpid() & 0xFFFF;
505
506    LOG_FAILURE_RETRY(__android_log_btwrite(0, EVENT_TYPE_LONG, &v, sizeof(v)));
507}
508
509TEST(logcat, blocking_tail) {
510    FILE *fp;
511    unsigned long long v = 0xA55FDEADBEEF0000ULL;
512
513    pid_t pid = getpid();
514
515    v += pid & 0xFFFF;
516
517    LOG_FAILURE_RETRY(__android_log_btwrite(0, EVENT_TYPE_LONG, &v, sizeof(v)));
518
519    v &= 0xFFFAFFFFFFFFFFFFULL;
520
521    ASSERT_TRUE(NULL != (fp = popen(
522      "( trap exit HUP QUIT INT PIPE KILL ; sleep 6; echo DONE )&"
523      " logcat -v brief -b events -T 5 2>&1",
524      "r")));
525
526    char buffer[BIG_BUFFER];
527
528    int count = 0;
529
530    int signals = 0;
531
532    signal(SIGALRM, caught_blocking_tail);
533    alarm(2);
534    while (fgets(buffer, sizeof(buffer), fp)) {
535
536        if (!strncmp(buffer, "DONE", 4)) {
537            break;
538        }
539
540        ++count;
541
542        int p;
543        unsigned long long l;
544
545        if ((2 != sscanf(buffer, "I/[0] ( %u): %lld", &p, &l))
546         || (p != pid)) {
547            continue;
548        }
549
550        if (l == v) {
551            if (count >= 5) {
552                ++signals;
553            }
554            break;
555        }
556    }
557    alarm(0);
558    signal(SIGALRM, SIG_DFL);
559
560    // Generate SIGPIPE
561    fclose(fp);
562    caught_blocking_tail(0);
563
564    pclose(fp);
565
566    EXPECT_LE(2, count);
567
568    EXPECT_EQ(1, signals);
569}
570
571TEST(logcat, logrotate) {
572    static const char form[] = "/data/local/tmp/logcat.logrotate.XXXXXX";
573    char buf[sizeof(form)];
574    ASSERT_TRUE(NULL != mkdtemp(strcpy(buf, form)));
575
576    static const char comm[] = "logcat -b radio -b events -b system -b main"
577                                     " -d -f %s/log.txt -n 7 -r 1";
578    char command[sizeof(buf) + sizeof(comm)];
579    snprintf(command, sizeof(command), comm, buf);
580
581    int ret;
582    EXPECT_FALSE((ret = system(command)));
583    if (!ret) {
584        snprintf(command, sizeof(command), "ls -s %s 2>/dev/null", buf);
585
586        FILE *fp;
587        EXPECT_TRUE(NULL != (fp = popen(command, "r")));
588        if (fp) {
589            char buffer[BIG_BUFFER];
590            int count = 0;
591
592            while (fgets(buffer, sizeof(buffer), fp)) {
593                static const char total[] = "total ";
594                int num;
595                char c;
596
597                if ((2 == sscanf(buffer, "%d log.tx%c", &num, &c)) &&
598                        (num <= 40)) {
599                    ++count;
600                } else if (strncmp(buffer, total, sizeof(total) - 1)) {
601                    fprintf(stderr, "WARNING: Parse error: %s", buffer);
602                }
603            }
604            pclose(fp);
605            if ((count != 7) && (count != 8)) {
606                fprintf(stderr, "count=%d\n", count);
607            }
608            EXPECT_TRUE(count == 7 || count == 8);
609        }
610    }
611    snprintf(command, sizeof(command), "rm -rf %s", buf);
612    EXPECT_FALSE(system(command));
613}
614
615TEST(logcat, logrotate_suffix) {
616    static const char tmp_out_dir_form[] = "/data/local/tmp/logcat.logrotate.XXXXXX";
617    char tmp_out_dir[sizeof(tmp_out_dir_form)];
618    ASSERT_TRUE(NULL != mkdtemp(strcpy(tmp_out_dir, tmp_out_dir_form)));
619
620    static const char logcat_cmd[] = "logcat -b radio -b events -b system -b main"
621                                     " -d -f %s/log.txt -n 10 -r 1";
622    char command[sizeof(tmp_out_dir) + sizeof(logcat_cmd)];
623    snprintf(command, sizeof(command), logcat_cmd, tmp_out_dir);
624
625    int ret;
626    EXPECT_FALSE((ret = system(command)));
627    if (!ret) {
628        snprintf(command, sizeof(command), "ls %s 2>/dev/null", tmp_out_dir);
629
630        FILE *fp;
631        EXPECT_TRUE(NULL != (fp = popen(command, "r")));
632        char buffer[BIG_BUFFER];
633        int log_file_count = 0;
634
635        while (fgets(buffer, sizeof(buffer), fp)) {
636            static const char rotated_log_filename_prefix[] = "log.txt.";
637            static const size_t rotated_log_filename_prefix_len =
638                strlen(rotated_log_filename_prefix);
639            static const char log_filename[] = "log.txt";
640
641            if (!strncmp(buffer, rotated_log_filename_prefix, rotated_log_filename_prefix_len)) {
642              // Rotated file should have form log.txt.##
643              char* rotated_log_filename_suffix = buffer + rotated_log_filename_prefix_len;
644              char* endptr;
645              const long int suffix_value = strtol(rotated_log_filename_suffix, &endptr, 10);
646              EXPECT_EQ(rotated_log_filename_suffix + 2, endptr);
647              EXPECT_LE(suffix_value, 10);
648              EXPECT_GT(suffix_value, 0);
649              ++log_file_count;
650              continue;
651            }
652
653            if (!strncmp(buffer, log_filename, strlen(log_filename))) {
654              ++log_file_count;
655              continue;
656            }
657
658            fprintf(stderr, "ERROR: Unexpected file: %s", buffer);
659            ADD_FAILURE();
660        }
661        pclose(fp);
662        EXPECT_EQ(11, log_file_count);
663    }
664    snprintf(command, sizeof(command), "rm -rf %s", tmp_out_dir);
665    EXPECT_FALSE(system(command));
666}
667
668TEST(logcat, logrotate_continue) {
669    static const char tmp_out_dir_form[] = "/data/local/tmp/logcat.logrotate.XXXXXX";
670    char tmp_out_dir[sizeof(tmp_out_dir_form)];
671    ASSERT_TRUE(NULL != mkdtemp(strcpy(tmp_out_dir, tmp_out_dir_form)));
672
673    static const char log_filename[] = "log.txt";
674    static const char logcat_cmd[] = "logcat -b all -d -f %s/%s -n 256 -r 1024";
675    static const char cleanup_cmd[] = "rm -rf %s";
676    char command[sizeof(tmp_out_dir) + sizeof(logcat_cmd) + sizeof(log_filename)];
677    snprintf(command, sizeof(command), logcat_cmd, tmp_out_dir, log_filename);
678
679    int ret;
680    EXPECT_FALSE((ret = system(command)));
681    if (ret) {
682        snprintf(command, sizeof(command), cleanup_cmd, tmp_out_dir);
683        EXPECT_FALSE(system(command));
684        return;
685    }
686    FILE *fp;
687    snprintf(command, sizeof(command), "%s/%s", tmp_out_dir, log_filename);
688    EXPECT_TRUE(NULL != ((fp = fopen(command, "r"))));
689    if (!fp) {
690        snprintf(command, sizeof(command), cleanup_cmd, tmp_out_dir);
691        EXPECT_FALSE(system(command));
692        return;
693    }
694    char *line = NULL;
695    char *last_line = NULL; // this line is allowed to stutter, one-line overlap
696    char *second_last_line = NULL;
697    size_t len = 0;
698    while (getline(&line, &len, fp) != -1) {
699        free(second_last_line);
700        second_last_line = last_line;
701        last_line = line;
702        line = NULL;
703    }
704    fclose(fp);
705    free(line);
706    if (second_last_line == NULL) {
707        fprintf(stderr, "No second to last line, using last, test may fail\n");
708        second_last_line = last_line;
709        last_line = NULL;
710    }
711    free(last_line);
712    EXPECT_TRUE(NULL != second_last_line);
713    if (!second_last_line) {
714        snprintf(command, sizeof(command), cleanup_cmd, tmp_out_dir);
715        EXPECT_FALSE(system(command));
716        return;
717    }
718    // re-run the command, it should only add a few lines more content if it
719    // continues where it left off.
720    snprintf(command, sizeof(command), logcat_cmd, tmp_out_dir, log_filename);
721    EXPECT_FALSE((ret = system(command)));
722    if (ret) {
723        snprintf(command, sizeof(command), cleanup_cmd, tmp_out_dir);
724        EXPECT_FALSE(system(command));
725        return;
726    }
727    DIR *dir;
728    EXPECT_TRUE(NULL != (dir = opendir(tmp_out_dir)));
729    if (!dir) {
730        snprintf(command, sizeof(command), cleanup_cmd, tmp_out_dir);
731        EXPECT_FALSE(system(command));
732        return;
733    }
734    struct dirent *entry;
735    unsigned count = 0;
736    while ((entry = readdir(dir))) {
737        if (strncmp(entry->d_name, log_filename, sizeof(log_filename) - 1)) {
738            continue;
739        }
740        snprintf(command, sizeof(command), "%s/%s", tmp_out_dir, entry->d_name);
741        EXPECT_TRUE(NULL != ((fp = fopen(command, "r"))));
742        if (!fp) {
743            fprintf(stderr, "%s ?\n", command);
744            continue;
745        }
746        line = NULL;
747        size_t number = 0;
748        while (getline(&line, &len, fp) != -1) {
749            ++number;
750            if (!strcmp(line, second_last_line)) {
751                EXPECT_TRUE(++count <= 1);
752                fprintf(stderr, "%s(%zu):\n", entry->d_name, number);
753            }
754        }
755        fclose(fp);
756        free(line);
757        unlink(command);
758    }
759    closedir(dir);
760    if (count > 1) {
761        char *brk = strpbrk(second_last_line, "\r\n");
762        if (!brk) {
763            brk = second_last_line + strlen(second_last_line);
764        }
765        fprintf(stderr, "\"%.*s\" occured %u times\n",
766            (int)(brk - second_last_line), second_last_line, count);
767    }
768    free(second_last_line);
769
770    snprintf(command, sizeof(command), cleanup_cmd, tmp_out_dir);
771    EXPECT_FALSE(system(command));
772}
773
774TEST(logcat, logrotate_clear) {
775    static const char tmp_out_dir_form[] = "/data/local/tmp/logcat.logrotate.XXXXXX";
776    char tmp_out_dir[sizeof(tmp_out_dir_form)];
777    ASSERT_TRUE(NULL != mkdtemp(strcpy(tmp_out_dir, tmp_out_dir_form)));
778
779    static const char log_filename[] = "log.txt";
780    static const unsigned num_val = 32;
781    static const char logcat_cmd[] = "logcat -b all -d -f %s/%s -n %d -r 1";
782    static const char clear_cmd[] = " -c";
783    static const char cleanup_cmd[] = "rm -rf %s";
784    char command[sizeof(tmp_out_dir) + sizeof(logcat_cmd) + sizeof(log_filename) + sizeof(clear_cmd) + 32];
785
786    // Run command with all data
787    {
788        snprintf(command, sizeof(command) - sizeof(clear_cmd),
789                 logcat_cmd, tmp_out_dir, log_filename, num_val);
790
791        int ret;
792        EXPECT_FALSE((ret = system(command)));
793        if (ret) {
794            snprintf(command, sizeof(command), cleanup_cmd, tmp_out_dir);
795            EXPECT_FALSE(system(command));
796            return;
797        }
798        std::unique_ptr<DIR, decltype(&closedir)> dir(opendir(tmp_out_dir), closedir);
799        EXPECT_NE(nullptr, dir);
800        if (!dir) {
801            snprintf(command, sizeof(command), cleanup_cmd, tmp_out_dir);
802            EXPECT_FALSE(system(command));
803            return;
804        }
805        struct dirent *entry;
806        unsigned count = 0;
807        while ((entry = readdir(dir.get()))) {
808            if (strncmp(entry->d_name, log_filename, sizeof(log_filename) - 1)) {
809                continue;
810            }
811            ++count;
812        }
813        EXPECT_EQ(count, num_val + 1);
814    }
815
816    {
817        // Now with -c option tacked onto the end
818        strcat(command, clear_cmd);
819
820        int ret;
821        EXPECT_FALSE((ret = system(command)));
822        if (ret) {
823            snprintf(command, sizeof(command), cleanup_cmd, tmp_out_dir);
824            EXPECT_FALSE(system(command));
825            return;
826        }
827        std::unique_ptr<DIR, decltype(&closedir)> dir(opendir(tmp_out_dir), closedir);
828        EXPECT_NE(nullptr, dir);
829        if (!dir) {
830            snprintf(command, sizeof(command), cleanup_cmd, tmp_out_dir);
831            EXPECT_FALSE(system(command));
832            return;
833        }
834        struct dirent *entry;
835        unsigned count = 0;
836        while ((entry = readdir(dir.get()))) {
837            if (strncmp(entry->d_name, log_filename, sizeof(log_filename) - 1)) {
838                continue;
839            }
840            fprintf(stderr, "Found %s/%s!!!\n", tmp_out_dir, entry->d_name);
841            ++count;
842        }
843        EXPECT_EQ(count, 0U);
844    }
845
846    snprintf(command, sizeof(command), cleanup_cmd, tmp_out_dir);
847    EXPECT_FALSE(system(command));
848}
849
850TEST(logcat, logrotate_nodir) {
851    // expect logcat to error out on writing content and exit(1) for nodir
852    EXPECT_EQ(W_EXITCODE(1, 0),
853              system("logcat -b all -d"
854                     " -f /das/nein/gerfingerpoken/logcat/log.txt"
855                     " -n 256 -r 1024"));
856}
857
858static void caught_blocking_clear(int /*signum*/) {
859    unsigned long long v = 0xDEADBEEFA55C0000ULL;
860
861    v += getpid() & 0xFFFF;
862
863    LOG_FAILURE_RETRY(__android_log_btwrite(0, EVENT_TYPE_LONG, &v, sizeof(v)));
864}
865
866TEST(logcat, blocking_clear) {
867    FILE *fp;
868    unsigned long long v = 0xDEADBEEFA55C0000ULL;
869
870    pid_t pid = getpid();
871
872    v += pid & 0xFFFF;
873
874    // This test is racey; an event occurs between clear and dump.
875    // We accept that we will get a false positive, but never a false negative.
876    ASSERT_TRUE(NULL != (fp = popen(
877      "( trap exit HUP QUIT INT PIPE KILL ; sleep 6; echo DONE )&"
878      " logcat -b events -c 2>&1 ;"
879      " logcat -v brief -b events 2>&1",
880      "r")));
881
882    char buffer[BIG_BUFFER];
883
884    int count = 0;
885
886    int signals = 0;
887
888    signal(SIGALRM, caught_blocking_clear);
889    alarm(2);
890    while (fgets(buffer, sizeof(buffer), fp)) {
891
892        if (!strncmp(buffer, "clearLog: ", 10)) {
893            fprintf(stderr, "WARNING: Test lacks permission to run :-(\n");
894            count = signals = 1;
895            break;
896        }
897
898        if (!strncmp(buffer, "DONE", 4)) {
899            break;
900        }
901
902        ++count;
903
904        int p;
905        unsigned long long l;
906
907        if ((2 != sscanf(buffer, "I/[0] ( %u): %lld", &p, &l))
908         || (p != pid)) {
909            continue;
910        }
911
912        if (l == v) {
913            if (count > 1) {
914                fprintf(stderr, "WARNING: Possible false positive\n");
915            }
916            ++signals;
917            break;
918        }
919    }
920    alarm(0);
921    signal(SIGALRM, SIG_DFL);
922
923    // Generate SIGPIPE
924    fclose(fp);
925    caught_blocking_clear(0);
926
927    pclose(fp);
928
929    EXPECT_LE(1, count);
930
931    EXPECT_EQ(1, signals);
932}
933
934static bool get_white_black(char **list) {
935    FILE *fp;
936
937    fp = popen("logcat -p 2>/dev/null", "r");
938    if (fp == NULL) {
939        fprintf(stderr, "ERROR: logcat -p 2>/dev/null\n");
940        return false;
941    }
942
943    char buffer[BIG_BUFFER];
944
945    while (fgets(buffer, sizeof(buffer), fp)) {
946        char *hold = *list;
947        char *buf = buffer;
948	while (isspace(*buf)) {
949            ++buf;
950        }
951        char *end = buf + strlen(buf);
952        while (isspace(*--end) && (end >= buf)) {
953            *end = '\0';
954        }
955        if (end < buf) {
956            continue;
957        }
958        if (hold) {
959            asprintf(list, "%s %s", hold, buf);
960            free(hold);
961        } else {
962            asprintf(list, "%s", buf);
963        }
964    }
965    pclose(fp);
966    return *list != NULL;
967}
968
969static bool set_white_black(const char *list) {
970    FILE *fp;
971
972    char buffer[BIG_BUFFER];
973
974    snprintf(buffer, sizeof(buffer), "logcat -P '%s' 2>&1", list ? list : "");
975    fp = popen(buffer, "r");
976    if (fp == NULL) {
977        fprintf(stderr, "ERROR: %s\n", buffer);
978        return false;
979    }
980
981    while (fgets(buffer, sizeof(buffer), fp)) {
982        char *buf = buffer;
983	while (isspace(*buf)) {
984            ++buf;
985        }
986        char *end = buf + strlen(buf);
987        while ((end > buf) && isspace(*--end)) {
988            *end = '\0';
989        }
990        if (end <= buf) {
991            continue;
992        }
993        fprintf(stderr, "%s\n", buf);
994        pclose(fp);
995        return false;
996    }
997    return pclose(fp) == 0;
998}
999
1000TEST(logcat, white_black_adjust) {
1001    char *list = NULL;
1002    char *adjust = NULL;
1003
1004    get_white_black(&list);
1005
1006    static const char adjustment[] = "~! 300/20 300/25 2000 ~1000/5 ~1000/30";
1007    ASSERT_EQ(true, set_white_black(adjustment));
1008    ASSERT_EQ(true, get_white_black(&adjust));
1009    EXPECT_STREQ(adjustment, adjust);
1010    free(adjust);
1011    adjust = NULL;
1012
1013    static const char adjustment2[] = "300/20 300/21 2000 ~1000";
1014    ASSERT_EQ(true, set_white_black(adjustment2));
1015    ASSERT_EQ(true, get_white_black(&adjust));
1016    EXPECT_STREQ(adjustment2, adjust);
1017    free(adjust);
1018    adjust = NULL;
1019
1020    ASSERT_EQ(true, set_white_black(list));
1021    get_white_black(&adjust);
1022    EXPECT_STREQ(list ? list : "", adjust ? adjust : "");
1023    free(adjust);
1024    adjust = NULL;
1025
1026    free(list);
1027    list = NULL;
1028}
1029
1030TEST(logcat, regex) {
1031    FILE *fp;
1032    int count = 0;
1033
1034    char buffer[BIG_BUFFER];
1035
1036    snprintf(buffer, sizeof(buffer), "logcat --pid %d -d -e logcat_test_a+b", getpid());
1037
1038    LOG_FAILURE_RETRY(__android_log_print(ANDROID_LOG_WARN, "logcat_test", "logcat_test_ab"));
1039    LOG_FAILURE_RETRY(__android_log_print(ANDROID_LOG_WARN, "logcat_test", "logcat_test_b"));
1040    LOG_FAILURE_RETRY(__android_log_print(ANDROID_LOG_WARN, "logcat_test", "logcat_test_aaaab"));
1041    LOG_FAILURE_RETRY(__android_log_print(ANDROID_LOG_WARN, "logcat_test", "logcat_test_aaaa"));
1042
1043    // Let the logs settle
1044    sleep(1);
1045
1046    ASSERT_TRUE(NULL != (fp = popen(buffer, "r")));
1047
1048    while (fgets(buffer, sizeof(buffer), fp)) {
1049        if (!strncmp(begin, buffer, sizeof(begin) - 1)) {
1050            continue;
1051        }
1052
1053        EXPECT_TRUE(strstr(buffer, "logcat_test_") != NULL);
1054
1055        count++;
1056    }
1057
1058    pclose(fp);
1059
1060    ASSERT_EQ(2, count);
1061}
1062
1063TEST(logcat, maxcount) {
1064    FILE *fp;
1065    int count = 0;
1066
1067    char buffer[BIG_BUFFER];
1068
1069    snprintf(buffer, sizeof(buffer), "logcat --pid %d -d --max-count 3", getpid());
1070
1071    LOG_FAILURE_RETRY(__android_log_print(ANDROID_LOG_WARN, "logcat_test", "logcat_test"));
1072    LOG_FAILURE_RETRY(__android_log_print(ANDROID_LOG_WARN, "logcat_test", "logcat_test"));
1073    LOG_FAILURE_RETRY(__android_log_print(ANDROID_LOG_WARN, "logcat_test", "logcat_test"));
1074    LOG_FAILURE_RETRY(__android_log_print(ANDROID_LOG_WARN, "logcat_test", "logcat_test"));
1075
1076    // Let the logs settle
1077    sleep(1);
1078
1079    ASSERT_TRUE(NULL != (fp = popen(buffer, "r")));
1080
1081    while (fgets(buffer, sizeof(buffer), fp)) {
1082        if (!strncmp(begin, buffer, sizeof(begin) - 1)) {
1083            continue;
1084        }
1085
1086        count++;
1087    }
1088
1089    pclose(fp);
1090
1091    ASSERT_EQ(3, count);
1092}
1093