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