• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
1 /*
2  * Copyright (C) 2013-2016 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 <errno.h>
20 #include <fcntl.h>
21 #include <inttypes.h>
22 #include <pthread.h>
23 #include <semaphore.h>
24 #include <signal.h>
25 #include <stdio.h>
26 #include <string.h>
27 #include <sys/types.h>
28 #include <unistd.h>
29 
30 #include <string>
31 
32 #include <android-base/file.h>
33 #include <android-base/macros.h>
34 #include <android-base/stringprintf.h>
35 #ifdef __ANDROID__  // includes sys/properties.h which does not exist outside
36 #include <cutils/properties.h>
37 #endif
38 #include <gtest/gtest.h>
39 #include <log/log_event_list.h>
40 #include <log/log_properties.h>
41 #include <log/log_transport.h>
42 #include <log/logprint.h>
43 #include <private/android_filesystem_config.h>
44 #include <private/android_logger.h>
45 
46 #ifndef TEST_PREFIX
47 #ifdef TEST_LOGGER
48 #define TEST_PREFIX android_set_log_transport(TEST_LOGGER);
49 // make sure we always run code despite overrides if compiled for android
50 #elif defined(__ANDROID__)
51 #define TEST_PREFIX
52 #endif
53 #endif
54 
55 #ifdef USING_LOGGER_STDERR
56 #define SUPPORTS_END_TO_END 0
57 #else
58 #define SUPPORTS_END_TO_END 1
59 #endif
60 
61 // enhanced version of LOG_FAILURE_RETRY to add support for EAGAIN and
62 // non-syscall libs. Since we are only using this in the emergency of
63 // a signal to stuff a terminating code into the logs, we will spin rather
64 // than try a usleep.
65 #define LOG_FAILURE_RETRY(exp)                                           \
66   ({                                                                     \
67     typeof(exp) _rc;                                                     \
68     do {                                                                 \
69       _rc = (exp);                                                       \
70     } while (((_rc == -1) && ((errno == EINTR) || (errno == EAGAIN))) || \
71              (_rc == -EINTR) || (_rc == -EAGAIN));                       \
72     _rc;                                                                 \
73   })
74 
TEST(liblog,__android_log_btwrite)75 TEST(liblog, __android_log_btwrite) {
76 #ifdef TEST_PREFIX
77   TEST_PREFIX
78 #endif
79   int intBuf = 0xDEADBEEF;
80   EXPECT_LT(0,
81             __android_log_btwrite(0, EVENT_TYPE_INT, &intBuf, sizeof(intBuf)));
82   long long longBuf = 0xDEADBEEFA55A5AA5;
83   EXPECT_LT(
84       0, __android_log_btwrite(0, EVENT_TYPE_LONG, &longBuf, sizeof(longBuf)));
85   usleep(1000);
86   char Buf[] = "\20\0\0\0DeAdBeEfA55a5aA5";
87   EXPECT_LT(0,
88             __android_log_btwrite(0, EVENT_TYPE_STRING, Buf, sizeof(Buf) - 1));
89   usleep(1000);
90 }
91 
92 #if (defined(__ANDROID__) && defined(USING_LOGGER_DEFAULT))
popenToString(const std::string & command)93 static std::string popenToString(const std::string& command) {
94   std::string ret;
95 
96   FILE* fp = popen(command.c_str(), "re");
97   if (fp) {
98     if (!android::base::ReadFdToString(fileno(fp), &ret)) ret = "";
99     pclose(fp);
100   }
101   return ret;
102 }
103 
104 #ifndef NO_PSTORE
isPmsgActive()105 static bool isPmsgActive() {
106   pid_t pid = getpid();
107 
108   std::string myPidFds =
109       popenToString(android::base::StringPrintf("ls -l /proc/%d/fd", pid));
110   if (myPidFds.length() == 0) return true;  // guess it is?
111 
112   return std::string::npos != myPidFds.find(" -> /dev/pmsg0");
113 }
114 #endif /* NO_PSTORE */
115 
isLogdwActive()116 static bool isLogdwActive() {
117   std::string logdwSignature =
118       popenToString("grep -a /dev/socket/logdw /proc/net/unix");
119   size_t beginning = logdwSignature.find(' ');
120   if (beginning == std::string::npos) return true;
121   beginning = logdwSignature.find(' ', beginning + 1);
122   if (beginning == std::string::npos) return true;
123   size_t end = logdwSignature.find(' ', beginning + 1);
124   if (end == std::string::npos) return true;
125   end = logdwSignature.find(' ', end + 1);
126   if (end == std::string::npos) return true;
127   end = logdwSignature.find(' ', end + 1);
128   if (end == std::string::npos) return true;
129   end = logdwSignature.find(' ', end + 1);
130   if (end == std::string::npos) return true;
131   std::string allLogdwEndpoints = popenToString(
132       "grep -a ' 00000002" + logdwSignature.substr(beginning, end - beginning) +
133       " ' /proc/net/unix | " +
134       "sed -n 's/.* \\([0-9][0-9]*\\)$/ -> socket:[\\1]/p'");
135   if (allLogdwEndpoints.length() == 0) return true;
136 
137   // NB: allLogdwEndpoints has some false positives in it, but those
138   // strangers do not overlap with the simplistic activities inside this
139   // test suite.
140 
141   pid_t pid = getpid();
142 
143   std::string myPidFds =
144       popenToString(android::base::StringPrintf("ls -l /proc/%d/fd", pid));
145   if (myPidFds.length() == 0) return true;
146 
147   // NB: fgrep with multiple strings is broken in Android
148   for (beginning = 0;
149        (end = allLogdwEndpoints.find('\n', beginning)) != std::string::npos;
150        beginning = end + 1) {
151     if (myPidFds.find(allLogdwEndpoints.substr(beginning, end - beginning)) !=
152         std::string::npos)
153       return true;
154   }
155   return false;
156 }
157 
158 static bool tested__android_log_close;
159 #endif
160 
TEST(liblog,__android_log_btwrite__android_logger_list_read)161 TEST(liblog, __android_log_btwrite__android_logger_list_read) {
162 #ifdef __ANDROID__
163 #ifdef TEST_PREFIX
164   TEST_PREFIX
165 #endif
166   struct logger_list* logger_list;
167 
168   pid_t pid = getpid();
169 
170   ASSERT_TRUE(NULL !=
171               (logger_list = android_logger_list_open(
172                    LOG_ID_EVENTS, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK,
173                    1000, pid)));
174 
175   log_time ts(CLOCK_MONOTONIC);
176   EXPECT_LT(0, __android_log_btwrite(0, EVENT_TYPE_LONG, &ts, sizeof(ts)));
177 #ifdef USING_LOGGER_DEFAULT
178   // Check that we can close and reopen the logger
179   bool logdwActiveAfter__android_log_btwrite;
180   if (getuid() == AID_ROOT) {
181     tested__android_log_close = true;
182 #ifndef NO_PSTORE
183     bool pmsgActiveAfter__android_log_btwrite = isPmsgActive();
184     EXPECT_TRUE(pmsgActiveAfter__android_log_btwrite);
185 #endif /* NO_PSTORE */
186     logdwActiveAfter__android_log_btwrite = isLogdwActive();
187     EXPECT_TRUE(logdwActiveAfter__android_log_btwrite);
188   } else if (!tested__android_log_close) {
189     fprintf(stderr, "WARNING: can not test __android_log_close()\n");
190   }
191   __android_log_close();
192   if (getuid() == AID_ROOT) {
193 #ifndef NO_PSTORE
194     bool pmsgActiveAfter__android_log_close = isPmsgActive();
195     EXPECT_FALSE(pmsgActiveAfter__android_log_close);
196 #endif /* NO_PSTORE */
197     bool logdwActiveAfter__android_log_close = isLogdwActive();
198     EXPECT_FALSE(logdwActiveAfter__android_log_close);
199   }
200 #endif
201 
202   log_time ts1(CLOCK_MONOTONIC);
203   EXPECT_LT(0, __android_log_btwrite(0, EVENT_TYPE_LONG, &ts1, sizeof(ts1)));
204 #ifdef USING_LOGGER_DEFAULT
205   if (getuid() == AID_ROOT) {
206 #ifndef NO_PSTORE
207     bool pmsgActiveAfter__android_log_btwrite = isPmsgActive();
208     EXPECT_TRUE(pmsgActiveAfter__android_log_btwrite);
209 #endif /* NO_PSTORE */
210     logdwActiveAfter__android_log_btwrite = isLogdwActive();
211     EXPECT_TRUE(logdwActiveAfter__android_log_btwrite);
212   }
213 #endif
214   usleep(1000000);
215 
216   int count = 0;
217   int second_count = 0;
218 
219   for (;;) {
220     log_msg log_msg;
221     if (android_logger_list_read(logger_list, &log_msg) <= 0) {
222       break;
223     }
224 
225     EXPECT_EQ(log_msg.entry.pid, pid);
226 
227     if ((log_msg.entry.len != sizeof(android_log_event_long_t)) ||
228         (log_msg.id() != LOG_ID_EVENTS)) {
229       continue;
230     }
231 
232     android_log_event_long_t* eventData;
233     eventData = reinterpret_cast<android_log_event_long_t*>(log_msg.msg());
234 
235     if (!eventData || (eventData->payload.type != EVENT_TYPE_LONG)) {
236       continue;
237     }
238 
239     log_time tx(reinterpret_cast<char*>(&eventData->payload.data));
240     if (ts == tx) {
241       ++count;
242     } else if (ts1 == tx) {
243       ++second_count;
244     }
245   }
246 
247   EXPECT_EQ(SUPPORTS_END_TO_END, count);
248   EXPECT_EQ(SUPPORTS_END_TO_END, second_count);
249 
250   android_logger_list_close(logger_list);
251 #else
252   GTEST_LOG_(INFO) << "This test does nothing.\n";
253 #endif
254 }
255 
256 #ifdef __ANDROID__
print_transport(const char * prefix,int logger)257 static void print_transport(const char* prefix, int logger) {
258   static const char orstr[] = " | ";
259 
260   if (!prefix) {
261     prefix = "";
262   }
263   if (logger < 0) {
264     fprintf(stderr, "%s%s\n", prefix, strerror(-logger));
265     return;
266   }
267 
268   if (logger == LOGGER_DEFAULT) {
269     fprintf(stderr, "%sLOGGER_DEFAULT", prefix);
270     prefix = orstr;
271   }
272   if (logger & LOGGER_LOGD) {
273     fprintf(stderr, "%sLOGGER_LOGD", prefix);
274     prefix = orstr;
275   }
276   if (logger & LOGGER_KERNEL) {
277     fprintf(stderr, "%sLOGGER_KERNEL", prefix);
278     prefix = orstr;
279   }
280   if (logger & LOGGER_NULL) {
281     fprintf(stderr, "%sLOGGER_NULL", prefix);
282     prefix = orstr;
283   }
284   if (logger & LOGGER_STDERR) {
285     fprintf(stderr, "%sLOGGER_STDERR", prefix);
286     prefix = orstr;
287   }
288   logger &= ~(LOGGER_LOGD | LOGGER_KERNEL | LOGGER_NULL | LOGGER_STDERR);
289   if (logger) {
290     fprintf(stderr, "%s0x%x", prefix, logger);
291     prefix = orstr;
292   }
293   if (prefix == orstr) {
294     fprintf(stderr, "\n");
295   }
296 }
297 #endif
298 
299 // This test makes little sense standalone, and requires the tests ahead
300 // and behind us, to make us whole.  We could incorporate a prefix and
301 // suffix test to make this standalone, but opted to not complicate this.
TEST(liblog,android_set_log_transport)302 TEST(liblog, android_set_log_transport) {
303 #ifdef __ANDROID__
304 #ifdef TEST_PREFIX
305   TEST_PREFIX
306 #endif
307 
308   int logger = android_get_log_transport();
309   print_transport("android_get_log_transport = ", logger);
310   EXPECT_NE(LOGGER_NULL, logger);
311 
312   int ret;
313   EXPECT_EQ(LOGGER_NULL, ret = android_set_log_transport(LOGGER_NULL));
314   print_transport("android_set_log_transport = ", ret);
315   EXPECT_EQ(LOGGER_NULL, ret = android_get_log_transport());
316   print_transport("android_get_log_transport = ", ret);
317 
318   pid_t pid = getpid();
319 
320   struct logger_list* logger_list;
321   ASSERT_TRUE(NULL !=
322               (logger_list = android_logger_list_open(
323                    LOG_ID_EVENTS, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK,
324                    1000, pid)));
325 
326   log_time ts(CLOCK_MONOTONIC);
327   EXPECT_LT(0, __android_log_btwrite(0, EVENT_TYPE_LONG, &ts, sizeof(ts)));
328 
329   usleep(1000000);
330 
331   int count = 0;
332 
333   for (;;) {
334     log_msg log_msg;
335     if (android_logger_list_read(logger_list, &log_msg) <= 0) {
336       break;
337     }
338 
339     EXPECT_EQ(log_msg.entry.pid, pid);
340 
341     if ((log_msg.entry.len != sizeof(android_log_event_long_t)) ||
342         (log_msg.id() != LOG_ID_EVENTS)) {
343       continue;
344     }
345 
346     android_log_event_long_t* eventData;
347     eventData = reinterpret_cast<android_log_event_long_t*>(log_msg.msg());
348 
349     if (!eventData || (eventData->payload.type != EVENT_TYPE_LONG)) {
350       continue;
351     }
352 
353     log_time tx(reinterpret_cast<char*>(&eventData->payload.data));
354     if (ts == tx) {
355       ++count;
356     }
357   }
358 
359   android_logger_list_close(logger_list);
360 
361   EXPECT_EQ(logger, ret = android_set_log_transport(logger));
362   print_transport("android_set_log_transport = ", ret);
363   EXPECT_EQ(logger, ret = android_get_log_transport());
364   print_transport("android_get_log_transport = ", ret);
365 
366   // False negative if liblog.__android_log_btwrite__android_logger_list_read
367   // fails above, so we will likely succeed. But we will have so many
368   // failures elsewhere that it is probably not worthwhile for us to
369   // highlight yet another disappointment.
370   //
371   // We also expect failures in the following tests if the set does not
372   // react in an appropriate manner internally, yet passes, so we depend
373   // on this test being in the middle of a series of tests performed in
374   // the same process.
375   EXPECT_EQ(0, count);
376 #else
377   GTEST_LOG_(INFO) << "This test does nothing.\n";
378 #endif
379 }
380 
381 #ifdef TEST_PREFIX
get4LE(const uint8_t * src)382 static inline uint32_t get4LE(const uint8_t* src) {
383   return src[0] | (src[1] << 8) | (src[2] << 16) | (src[3] << 24);
384 }
385 
get4LE(const char * src)386 static inline uint32_t get4LE(const char* src) {
387   return get4LE(reinterpret_cast<const uint8_t*>(src));
388 }
389 #endif
390 
bswrite_test(const char * message)391 static void bswrite_test(const char* message) {
392 #ifdef TEST_PREFIX
393   TEST_PREFIX
394   struct logger_list* logger_list;
395 
396   pid_t pid = getpid();
397 
398   ASSERT_TRUE(NULL !=
399               (logger_list = android_logger_list_open(
400                    LOG_ID_EVENTS, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK,
401                    1000, pid)));
402 
403 #ifdef __ANDROID__
404   log_time ts(android_log_clockid());
405 #else
406   log_time ts(CLOCK_REALTIME);
407 #endif
408 
409   EXPECT_LT(0, __android_log_bswrite(0, message));
410   size_t num_lines = 1, size = 0, length = 0, total = 0;
411   const char* cp = message;
412   while (*cp) {
413     if (*cp == '\n') {
414       if (cp[1]) {
415         ++num_lines;
416       }
417     } else {
418       ++size;
419     }
420     ++cp;
421     ++total;
422     ++length;
423     if ((LOGGER_ENTRY_MAX_PAYLOAD - 4 - 1 - 4) <= length) {
424       break;
425     }
426   }
427   while (*cp) {
428     ++cp;
429     ++total;
430   }
431   usleep(1000000);
432 
433   int count = 0;
434 
435   for (;;) {
436     log_msg log_msg;
437     if (android_logger_list_read(logger_list, &log_msg) <= 0) {
438       break;
439     }
440 
441     EXPECT_EQ(log_msg.entry.pid, pid);
442 
443     if ((log_msg.entry.sec < (ts.tv_sec - 1)) ||
444         ((ts.tv_sec + 1) < log_msg.entry.sec) ||
445         ((size_t)log_msg.entry.len !=
446          (sizeof(android_log_event_string_t) + length)) ||
447         (log_msg.id() != LOG_ID_EVENTS)) {
448       continue;
449     }
450 
451     android_log_event_string_t* eventData;
452     eventData = reinterpret_cast<android_log_event_string_t*>(log_msg.msg());
453 
454     if (!eventData || (eventData->type != EVENT_TYPE_STRING)) {
455       continue;
456     }
457 
458     size_t len = get4LE(reinterpret_cast<char*>(&eventData->length));
459     if (len == total) {
460       ++count;
461 
462       AndroidLogFormat* logformat = android_log_format_new();
463       EXPECT_TRUE(NULL != logformat);
464       AndroidLogEntry entry;
465       char msgBuf[1024];
466       if (length != total) {
467         fprintf(stderr, "Expect \"Binary log entry conversion failed\"\n");
468       }
469       int processBinaryLogBuffer = android_log_processBinaryLogBuffer(
470           &log_msg.entry_v1, &entry, NULL, msgBuf, sizeof(msgBuf));
471       EXPECT_EQ((length == total) ? 0 : -1, processBinaryLogBuffer);
472       if ((processBinaryLogBuffer == 0) || entry.message) {
473         size_t line_overhead = 20;
474         if (pid > 99999) ++line_overhead;
475         if (pid > 999999) ++line_overhead;
476         fflush(stderr);
477         if (processBinaryLogBuffer) {
478           EXPECT_GT((int)((line_overhead * num_lines) + size),
479                     android_log_printLogLine(logformat, fileno(stderr), &entry));
480         } else {
481           EXPECT_EQ((int)((line_overhead * num_lines) + size),
482                     android_log_printLogLine(logformat, fileno(stderr), &entry));
483         }
484       }
485       android_log_format_free(logformat);
486     }
487   }
488 
489   EXPECT_EQ(SUPPORTS_END_TO_END, count);
490 
491   android_logger_list_close(logger_list);
492 #else
493   message = NULL;
494   GTEST_LOG_(INFO) << "This test does nothing.\n";
495 #endif
496 }
497 
TEST(liblog,__android_log_bswrite_and_print)498 TEST(liblog, __android_log_bswrite_and_print) {
499   bswrite_test("Hello World");
500 }
501 
TEST(liblog,__android_log_bswrite_and_print__empty_string)502 TEST(liblog, __android_log_bswrite_and_print__empty_string) {
503   bswrite_test("");
504 }
505 
TEST(liblog,__android_log_bswrite_and_print__newline_prefix)506 TEST(liblog, __android_log_bswrite_and_print__newline_prefix) {
507   bswrite_test("\nHello World\n");
508 }
509 
TEST(liblog,__android_log_bswrite_and_print__newline_space_prefix)510 TEST(liblog, __android_log_bswrite_and_print__newline_space_prefix) {
511   bswrite_test("\n Hello World \n");
512 }
513 
TEST(liblog,__android_log_bswrite_and_print__multiple_newline)514 TEST(liblog, __android_log_bswrite_and_print__multiple_newline) {
515   bswrite_test("one\ntwo\nthree\nfour\nfive\nsix\nseven\neight\nnine\nten");
516 }
517 
buf_write_test(const char * message)518 static void buf_write_test(const char* message) {
519 #ifdef TEST_PREFIX
520   TEST_PREFIX
521   struct logger_list* logger_list;
522 
523   pid_t pid = getpid();
524 
525   ASSERT_TRUE(
526       NULL !=
527       (logger_list = android_logger_list_open(
528            LOG_ID_MAIN, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 1000, pid)));
529 
530   static const char tag[] = "TEST__android_log_buf_write";
531 #ifdef __ANDROID__
532   log_time ts(android_log_clockid());
533 #else
534   log_time ts(CLOCK_REALTIME);
535 #endif
536 
537   EXPECT_LT(
538       0, __android_log_buf_write(LOG_ID_MAIN, ANDROID_LOG_INFO, tag, message));
539   size_t num_lines = 1, size = 0, length = 0;
540   const char* cp = message;
541   while (*cp) {
542     if (*cp == '\n') {
543       if (cp[1]) {
544         ++num_lines;
545       }
546     } else {
547       ++size;
548     }
549     ++length;
550     if ((LOGGER_ENTRY_MAX_PAYLOAD - 2 - sizeof(tag)) <= length) {
551       break;
552     }
553     ++cp;
554   }
555   usleep(1000000);
556 
557   int count = 0;
558 
559   for (;;) {
560     log_msg log_msg;
561     if (android_logger_list_read(logger_list, &log_msg) <= 0) {
562       break;
563     }
564 
565     ASSERT_EQ(log_msg.entry.pid, pid);
566 
567     if ((log_msg.entry.sec < (ts.tv_sec - 1)) ||
568         ((ts.tv_sec + 1) < log_msg.entry.sec) ||
569         ((size_t)log_msg.entry.len != (sizeof(tag) + length + 2)) ||
570         (log_msg.id() != LOG_ID_MAIN)) {
571       continue;
572     }
573 
574     ++count;
575 
576     AndroidLogFormat* logformat = android_log_format_new();
577     EXPECT_TRUE(NULL != logformat);
578     AndroidLogEntry entry;
579     int processLogBuffer =
580         android_log_processLogBuffer(&log_msg.entry_v1, &entry);
581     EXPECT_EQ(0, processLogBuffer);
582     if (processLogBuffer == 0) {
583       size_t line_overhead = 11;
584       if (pid > 99999) ++line_overhead;
585       if (pid > 999999) ++line_overhead;
586       fflush(stderr);
587       EXPECT_EQ((int)(((line_overhead + sizeof(tag)) * num_lines) + size),
588                 android_log_printLogLine(logformat, fileno(stderr), &entry));
589     }
590     android_log_format_free(logformat);
591   }
592 
593   EXPECT_EQ(SUPPORTS_END_TO_END, count);
594 
595   android_logger_list_close(logger_list);
596 #else
597   message = NULL;
598   GTEST_LOG_(INFO) << "This test does nothing.\n";
599 #endif
600 }
601 
TEST(liblog,__android_log_buf_write_and_print__empty)602 TEST(liblog, __android_log_buf_write_and_print__empty) {
603   buf_write_test("");
604 }
605 
TEST(liblog,__android_log_buf_write_and_print__newline_prefix)606 TEST(liblog, __android_log_buf_write_and_print__newline_prefix) {
607   buf_write_test("\nHello World\n");
608 }
609 
TEST(liblog,__android_log_buf_write_and_print__newline_space_prefix)610 TEST(liblog, __android_log_buf_write_and_print__newline_space_prefix) {
611   buf_write_test("\n Hello World \n");
612 }
613 
614 #ifdef USING_LOGGER_DEFAULT  // requires blocking reader functionality
615 #ifdef TEST_PREFIX
616 static unsigned signaled;
617 static log_time signal_time;
618 
619 /*
620  *  Strictly, we are not allowed to log messages in a signal context, but we
621  * do make an effort to keep the failure surface minimized, and this in-effect
622  * should catch any regressions in that effort. The odds of a logged message
623  * in a signal handler causing a lockup problem should be _very_ small.
624  */
caught_blocking_signal(int)625 static void caught_blocking_signal(int /*signum*/) {
626   unsigned long long v = 0xDEADBEEFA55A0000ULL;
627 
628   v += getpid() & 0xFFFF;
629 
630   ++signaled;
631   if ((signal_time.tv_sec == 0) && (signal_time.tv_nsec == 0)) {
632     signal_time = log_time(CLOCK_MONOTONIC);
633     signal_time.tv_sec += 2;
634   }
635 
636   LOG_FAILURE_RETRY(__android_log_btwrite(0, EVENT_TYPE_LONG, &v, sizeof(v)));
637 }
638 
639 // Fill in current process user and system time in 10ms increments
get_ticks(unsigned long long * uticks,unsigned long long * sticks)640 static void get_ticks(unsigned long long* uticks, unsigned long long* sticks) {
641   *uticks = *sticks = 0;
642 
643   pid_t pid = getpid();
644 
645   char buffer[512];
646   snprintf(buffer, sizeof(buffer), "/proc/%u/stat", pid);
647 
648   FILE* fp = fopen(buffer, "re");
649   if (!fp) {
650     return;
651   }
652 
653   char* cp = fgets(buffer, sizeof(buffer), fp);
654   fclose(fp);
655   if (!cp) {
656     return;
657   }
658 
659   pid_t d;
660   char s[sizeof(buffer)];
661   char c;
662   long long ll;
663   unsigned long long ull;
664 
665   if (15 != sscanf(buffer,
666                    "%d %s %c %lld %lld %lld %lld %lld %llu %llu %llu %llu %llu "
667                    "%llu %llu ",
668                    &d, s, &c, &ll, &ll, &ll, &ll, &ll, &ull, &ull, &ull, &ull,
669                    &ull, uticks, sticks)) {
670     *uticks = *sticks = 0;
671   }
672 }
673 #endif
674 
TEST(liblog,android_logger_list_read__cpu_signal)675 TEST(liblog, android_logger_list_read__cpu_signal) {
676 #ifdef TEST_PREFIX
677   TEST_PREFIX
678   struct logger_list* logger_list;
679   unsigned long long v = 0xDEADBEEFA55A0000ULL;
680 
681   pid_t pid = getpid();
682 
683   v += pid & 0xFFFF;
684 
685   ASSERT_TRUE(NULL != (logger_list = android_logger_list_open(
686                            LOG_ID_EVENTS, ANDROID_LOG_RDONLY, 1000, pid)));
687 
688   int count = 0;
689 
690   int signals = 0;
691 
692   unsigned long long uticks_start;
693   unsigned long long sticks_start;
694   get_ticks(&uticks_start, &sticks_start);
695 
696   const unsigned alarm_time = 10;
697 
698   memset(&signal_time, 0, sizeof(signal_time));
699 
700   signal(SIGALRM, caught_blocking_signal);
701   alarm(alarm_time);
702 
703   signaled = 0;
704 
705   do {
706     log_msg log_msg;
707     if (android_logger_list_read(logger_list, &log_msg) <= 0) {
708       break;
709     }
710 
711     alarm(alarm_time);
712 
713     ++count;
714 
715     ASSERT_EQ(log_msg.entry.pid, pid);
716 
717     if ((log_msg.entry.len != sizeof(android_log_event_long_t)) ||
718         (log_msg.id() != LOG_ID_EVENTS)) {
719       continue;
720     }
721 
722     android_log_event_long_t* eventData;
723     eventData = reinterpret_cast<android_log_event_long_t*>(log_msg.msg());
724 
725     if (!eventData || (eventData->payload.type != EVENT_TYPE_LONG)) {
726       continue;
727     }
728 
729     char* cp = reinterpret_cast<char*>(&eventData->payload.data);
730     unsigned long long l = cp[0] & 0xFF;
731     l |= (unsigned long long)(cp[1] & 0xFF) << 8;
732     l |= (unsigned long long)(cp[2] & 0xFF) << 16;
733     l |= (unsigned long long)(cp[3] & 0xFF) << 24;
734     l |= (unsigned long long)(cp[4] & 0xFF) << 32;
735     l |= (unsigned long long)(cp[5] & 0xFF) << 40;
736     l |= (unsigned long long)(cp[6] & 0xFF) << 48;
737     l |= (unsigned long long)(cp[7] & 0xFF) << 56;
738 
739     if (l == v) {
740       ++signals;
741       break;
742     }
743   } while (!signaled || (log_time(CLOCK_MONOTONIC) < signal_time));
744   alarm(0);
745   signal(SIGALRM, SIG_DFL);
746 
747   EXPECT_LE(1, count);
748 
749   EXPECT_EQ(1, signals);
750 
751   android_logger_list_close(logger_list);
752 
753   unsigned long long uticks_end;
754   unsigned long long sticks_end;
755   get_ticks(&uticks_end, &sticks_end);
756 
757   // Less than 1% in either user or system time, or both
758   const unsigned long long one_percent_ticks = alarm_time;
759   unsigned long long user_ticks = uticks_end - uticks_start;
760   unsigned long long system_ticks = sticks_end - sticks_start;
761   EXPECT_GT(one_percent_ticks, user_ticks);
762   EXPECT_GT(one_percent_ticks, system_ticks);
763   EXPECT_GT(one_percent_ticks, user_ticks + system_ticks);
764 #else
765   GTEST_LOG_(INFO) << "This test does nothing.\n";
766 #endif
767 }
768 
769 #ifdef TEST_PREFIX
770 /*
771  *  Strictly, we are not allowed to log messages in a signal context, the
772  * correct way to handle this is to ensure the messages are constructed in
773  * a thread; the signal handler should only unblock the thread.
774  */
775 static sem_t thread_trigger;
776 
caught_blocking_thread(int)777 static void caught_blocking_thread(int /*signum*/) {
778   sem_post(&thread_trigger);
779 }
780 
running_thread(void *)781 static void* running_thread(void*) {
782   unsigned long long v = 0xDEADBEAFA55A0000ULL;
783 
784   v += getpid() & 0xFFFF;
785 
786   struct timespec timeout;
787   clock_gettime(CLOCK_REALTIME, &timeout);
788   timeout.tv_sec += 55;
789   sem_timedwait(&thread_trigger, &timeout);
790 
791   ++signaled;
792   if ((signal_time.tv_sec == 0) && (signal_time.tv_nsec == 0)) {
793     signal_time = log_time(CLOCK_MONOTONIC);
794     signal_time.tv_sec += 2;
795   }
796 
797   LOG_FAILURE_RETRY(__android_log_btwrite(0, EVENT_TYPE_LONG, &v, sizeof(v)));
798 
799   return NULL;
800 }
801 
start_thread()802 static int start_thread() {
803   sem_init(&thread_trigger, 0, 0);
804 
805   pthread_attr_t attr;
806   if (pthread_attr_init(&attr)) {
807     return -1;
808   }
809 
810   struct sched_param param;
811 
812   memset(&param, 0, sizeof(param));
813   pthread_attr_setschedparam(&attr, &param);
814   pthread_attr_setschedpolicy(&attr, SCHED_BATCH);
815 
816   if (pthread_attr_setdetachstate(&attr, PTHREAD_CREATE_DETACHED)) {
817     pthread_attr_destroy(&attr);
818     return -1;
819   }
820 
821   pthread_t thread;
822   if (pthread_create(&thread, &attr, running_thread, NULL)) {
823     pthread_attr_destroy(&attr);
824     return -1;
825   }
826 
827   pthread_attr_destroy(&attr);
828   return 0;
829 }
830 #endif
831 
TEST(liblog,android_logger_list_read__cpu_thread)832 TEST(liblog, android_logger_list_read__cpu_thread) {
833 #ifdef TEST_PREFIX
834   TEST_PREFIX
835   struct logger_list* logger_list;
836   unsigned long long v = 0xDEADBEAFA55A0000ULL;
837 
838   pid_t pid = getpid();
839 
840   v += pid & 0xFFFF;
841 
842   ASSERT_TRUE(NULL != (logger_list = android_logger_list_open(
843                            LOG_ID_EVENTS, ANDROID_LOG_RDONLY, 1000, pid)));
844 
845   int count = 0;
846 
847   int signals = 0;
848 
849   unsigned long long uticks_start;
850   unsigned long long sticks_start;
851   get_ticks(&uticks_start, &sticks_start);
852 
853   const unsigned alarm_time = 10;
854 
855   memset(&signal_time, 0, sizeof(signal_time));
856 
857   signaled = 0;
858   EXPECT_EQ(0, start_thread());
859 
860   signal(SIGALRM, caught_blocking_thread);
861   alarm(alarm_time);
862 
863   do {
864     log_msg log_msg;
865     if (LOG_FAILURE_RETRY(android_logger_list_read(logger_list, &log_msg)) <= 0) {
866       break;
867     }
868 
869     alarm(alarm_time);
870 
871     ++count;
872 
873     ASSERT_EQ(log_msg.entry.pid, pid);
874 
875     if ((log_msg.entry.len != sizeof(android_log_event_long_t)) ||
876         (log_msg.id() != LOG_ID_EVENTS)) {
877       continue;
878     }
879 
880     android_log_event_long_t* eventData;
881     eventData = reinterpret_cast<android_log_event_long_t*>(log_msg.msg());
882 
883     if (!eventData || (eventData->payload.type != EVENT_TYPE_LONG)) {
884       continue;
885     }
886 
887     char* cp = reinterpret_cast<char*>(&eventData->payload.data);
888     unsigned long long l = cp[0] & 0xFF;
889     l |= (unsigned long long)(cp[1] & 0xFF) << 8;
890     l |= (unsigned long long)(cp[2] & 0xFF) << 16;
891     l |= (unsigned long long)(cp[3] & 0xFF) << 24;
892     l |= (unsigned long long)(cp[4] & 0xFF) << 32;
893     l |= (unsigned long long)(cp[5] & 0xFF) << 40;
894     l |= (unsigned long long)(cp[6] & 0xFF) << 48;
895     l |= (unsigned long long)(cp[7] & 0xFF) << 56;
896 
897     if (l == v) {
898       ++signals;
899       break;
900     }
901   } while (!signaled || (log_time(CLOCK_MONOTONIC) < signal_time));
902   alarm(0);
903   signal(SIGALRM, SIG_DFL);
904 
905   EXPECT_LE(1, count);
906 
907   EXPECT_EQ(1, signals);
908 
909   android_logger_list_close(logger_list);
910 
911   unsigned long long uticks_end;
912   unsigned long long sticks_end;
913   get_ticks(&uticks_end, &sticks_end);
914 
915   // Less than 1% in either user or system time, or both
916   const unsigned long long one_percent_ticks = alarm_time;
917   unsigned long long user_ticks = uticks_end - uticks_start;
918   unsigned long long system_ticks = sticks_end - sticks_start;
919   EXPECT_GT(one_percent_ticks, user_ticks);
920   EXPECT_GT(one_percent_ticks, system_ticks);
921   EXPECT_GT(one_percent_ticks, user_ticks + system_ticks);
922 #else
923   GTEST_LOG_(INFO) << "This test does nothing.\n";
924 #endif
925 }
926 #endif  // USING_LOGGER_DEFAULT
927 
928 #ifdef TEST_PREFIX
929 static const char max_payload_tag[] = "TEST_max_payload_and_longish_tag_XXXX";
930 #define SIZEOF_MAX_PAYLOAD_BUF \
931   (LOGGER_ENTRY_MAX_PAYLOAD - sizeof(max_payload_tag) - 1)
932 #endif
933 static const char max_payload_buf[] =
934     "LEONATO\n\
935 I learn in this letter that Don Peter of Arragon\n\
936 comes this night to Messina\n\
937 MESSENGER\n\
938 He is very near by this: he was not three leagues off\n\
939 when I left him\n\
940 LEONATO\n\
941 How many gentlemen have you lost in this action?\n\
942 MESSENGER\n\
943 But few of any sort, and none of name\n\
944 LEONATO\n\
945 A victory is twice itself when the achiever brings\n\
946 home full numbers. I find here that Don Peter hath\n\
947 bestowed much honour on a young Florentine called Claudio\n\
948 MESSENGER\n\
949 Much deserved on his part and equally remembered by\n\
950 Don Pedro: he hath borne himself beyond the\n\
951 promise of his age, doing, in the figure of a lamb,\n\
952 the feats of a lion: he hath indeed better\n\
953 bettered expectation than you must expect of me to\n\
954 tell you how\n\
955 LEONATO\n\
956 He hath an uncle here in Messina will be very much\n\
957 glad of it.\n\
958 MESSENGER\n\
959 I have already delivered him letters, and there\n\
960 appears much joy in him; even so much that joy could\n\
961 not show itself modest enough without a badge of\n\
962 bitterness.\n\
963 LEONATO\n\
964 Did he break out into tears?\n\
965 MESSENGER\n\
966 In great measure.\n\
967 LEONATO\n\
968 A kind overflow of kindness: there are no faces\n\
969 truer than those that are so washed. How much\n\
970 better is it to weep at joy than to joy at weeping!\n\
971 BEATRICE\n\
972 I pray you, is Signior Mountanto returned from the\n\
973 wars or no?\n\
974 MESSENGER\n\
975 I know none of that name, lady: there was none such\n\
976 in the army of any sort.\n\
977 LEONATO\n\
978 What is he that you ask for, niece?\n\
979 HERO\n\
980 My cousin means Signior Benedick of Padua.\n\
981 MESSENGER\n\
982 O, he's returned; and as pleasant as ever he was.\n\
983 BEATRICE\n\
984 He set up his bills here in Messina and challenged\n\
985 Cupid at the flight; and my uncle's fool, reading\n\
986 the challenge, subscribed for Cupid, and challenged\n\
987 him at the bird-bolt. I pray you, how many hath he\n\
988 killed and eaten in these wars? But how many hath\n\
989 he killed? for indeed I promised to eat all of his killing.\n\
990 LEONATO\n\
991 Faith, niece, you tax Signior Benedick too much;\n\
992 but he'll be meet with you, I doubt it not.\n\
993 MESSENGER\n\
994 He hath done good service, lady, in these wars.\n\
995 BEATRICE\n\
996 You had musty victual, and he hath holp to eat it:\n\
997 he is a very valiant trencherman; he hath an\n\
998 excellent stomach.\n\
999 MESSENGER\n\
1000 And a good soldier too, lady.\n\
1001 BEATRICE\n\
1002 And a good soldier to a lady: but what is he to a lord?\n\
1003 MESSENGER\n\
1004 A lord to a lord, a man to a man; stuffed with all\n\
1005 honourable virtues.\n\
1006 BEATRICE\n\
1007 It is so, indeed; he is no less than a stuffed man:\n\
1008 but for the stuffing,--well, we are all mortal.\n\
1009 LEONATO\n\
1010 You must not, sir, mistake my niece. There is a\n\
1011 kind of merry war betwixt Signior Benedick and her:\n\
1012 they never meet but there's a skirmish of wit\n\
1013 between them.\n\
1014 BEATRICE\n\
1015 Alas! he gets nothing by that. In our last\n\
1016 conflict four of his five wits went halting off, and\n\
1017 now is the whole man governed with one: so that if\n\
1018 he have wit enough to keep himself warm, let him\n\
1019 bear it for a difference between himself and his\n\
1020 horse; for it is all the wealth that he hath left,\n\
1021 to be known a reasonable creature. Who is his\n\
1022 companion now? He hath every month a new sworn brother.\n\
1023 MESSENGER\n\
1024 Is't possible?\n\
1025 BEATRICE\n\
1026 Very easily possible: he wears his faith but as\n\
1027 the fashion of his hat; it ever changes with the\n\
1028 next block.\n\
1029 MESSENGER\n\
1030 I see, lady, the gentleman is not in your books.\n\
1031 BEATRICE\n\
1032 No; an he were, I would burn my study. But, I pray\n\
1033 you, who is his companion? Is there no young\n\
1034 squarer now that will make a voyage with him to the devil?\n\
1035 MESSENGER\n\
1036 He is most in the company of the right noble Claudio.\n\
1037 BEATRICE\n\
1038 O Lord, he will hang upon him like a disease: he\n\
1039 is sooner caught than the pestilence, and the taker\n\
1040 runs presently mad. God help the noble Claudio! if\n\
1041 he have caught the Benedick, it will cost him a\n\
1042 thousand pound ere a' be cured.\n\
1043 MESSENGER\n\
1044 I will hold friends with you, lady.\n\
1045 BEATRICE\n\
1046 Do, good friend.\n\
1047 LEONATO\n\
1048 You will never run mad, niece.\n\
1049 BEATRICE\n\
1050 No, not till a hot January.\n\
1051 MESSENGER\n\
1052 Don Pedro is approached.\n\
1053 Enter DON PEDRO, DON JOHN, CLAUDIO, BENEDICK, and BALTHASAR\n\
1054 \n\
1055 DON PEDRO\n\
1056 Good Signior Leonato, you are come to meet your\n\
1057 trouble: the fashion of the world is to avoid\n\
1058 cost, and you encounter it\n\
1059 LEONATO\n\
1060 Never came trouble to my house in the likeness of your grace,\n\
1061 for trouble being gone, comfort should remain, but\n\
1062 when you depart from me, sorrow abides and happiness\n\
1063 takes his leave.";
1064 
TEST(liblog,max_payload)1065 TEST(liblog, max_payload) {
1066 #ifdef TEST_PREFIX
1067   TEST_PREFIX
1068   pid_t pid = getpid();
1069   char tag[sizeof(max_payload_tag)];
1070   memcpy(tag, max_payload_tag, sizeof(tag));
1071   snprintf(tag + sizeof(tag) - 5, 5, "%04X", pid & 0xFFFF);
1072 
1073   LOG_FAILURE_RETRY(__android_log_buf_write(LOG_ID_SYSTEM, ANDROID_LOG_INFO,
1074                                             tag, max_payload_buf));
1075   sleep(2);
1076 
1077   struct logger_list* logger_list;
1078 
1079   ASSERT_TRUE(NULL != (logger_list = android_logger_list_open(
1080                            LOG_ID_SYSTEM, ANDROID_LOG_RDONLY, 100, 0)));
1081 
1082   bool matches = false;
1083   ssize_t max_len = 0;
1084 
1085   for (;;) {
1086     log_msg log_msg;
1087     if (android_logger_list_read(logger_list, &log_msg) <= 0) {
1088       break;
1089     }
1090 
1091     if ((log_msg.entry.pid != pid) || (log_msg.id() != LOG_ID_SYSTEM)) {
1092       continue;
1093     }
1094 
1095     char* data = log_msg.msg();
1096 
1097     if (!data || strcmp(++data, tag)) {
1098       continue;
1099     }
1100 
1101     data += strlen(data) + 1;
1102 
1103     const char* left = data;
1104     const char* right = max_payload_buf;
1105     while (*left && *right && (*left == *right)) {
1106       ++left;
1107       ++right;
1108     }
1109 
1110     if (max_len <= (left - data)) {
1111       max_len = left - data + 1;
1112     }
1113 
1114     if (max_len > 512) {
1115       matches = true;
1116       break;
1117     }
1118   }
1119 
1120   android_logger_list_close(logger_list);
1121 
1122 #if SUPPORTS_END_TO_END
1123   EXPECT_EQ(true, matches);
1124 
1125   EXPECT_LE(SIZEOF_MAX_PAYLOAD_BUF, static_cast<size_t>(max_len));
1126 #else
1127   EXPECT_EQ(false, matches);
1128 #endif
1129 #else
1130   GTEST_LOG_(INFO) << "This test does nothing.\n";
1131 #endif
1132 }
1133 
TEST(liblog,__android_log_buf_print__maxtag)1134 TEST(liblog, __android_log_buf_print__maxtag) {
1135 #ifdef TEST_PREFIX
1136   TEST_PREFIX
1137   struct logger_list* logger_list;
1138 
1139   pid_t pid = getpid();
1140 
1141   ASSERT_TRUE(
1142       NULL !=
1143       (logger_list = android_logger_list_open(
1144            LOG_ID_MAIN, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 1000, pid)));
1145 
1146 #ifdef __ANDROID__
1147   log_time ts(android_log_clockid());
1148 #else
1149   log_time ts(CLOCK_REALTIME);
1150 #endif
1151 
1152   EXPECT_LT(0, __android_log_buf_print(LOG_ID_MAIN, ANDROID_LOG_INFO,
1153                                        max_payload_buf, max_payload_buf));
1154   usleep(1000000);
1155 
1156   int count = 0;
1157 
1158   for (;;) {
1159     log_msg log_msg;
1160     if (android_logger_list_read(logger_list, &log_msg) <= 0) {
1161       break;
1162     }
1163 
1164     ASSERT_EQ(log_msg.entry.pid, pid);
1165 
1166     if ((log_msg.entry.sec < (ts.tv_sec - 1)) ||
1167         ((ts.tv_sec + 1) < log_msg.entry.sec) ||
1168         ((size_t)log_msg.entry.len < LOGGER_ENTRY_MAX_PAYLOAD) ||
1169         (log_msg.id() != LOG_ID_MAIN)) {
1170       continue;
1171     }
1172 
1173     ++count;
1174 
1175     AndroidLogFormat* logformat = android_log_format_new();
1176     EXPECT_TRUE(NULL != logformat);
1177     AndroidLogEntry entry;
1178     int processLogBuffer =
1179         android_log_processLogBuffer(&log_msg.entry_v1, &entry);
1180     EXPECT_EQ(0, processLogBuffer);
1181     if (processLogBuffer == 0) {
1182       fflush(stderr);
1183       int printLogLine =
1184           android_log_printLogLine(logformat, fileno(stderr), &entry);
1185       // Legacy tag truncation
1186       EXPECT_LE(128, printLogLine);
1187       // Measured maximum if we try to print part of the tag as message
1188       EXPECT_GT(LOGGER_ENTRY_MAX_PAYLOAD * 13 / 8, printLogLine);
1189     }
1190     android_log_format_free(logformat);
1191   }
1192 
1193   EXPECT_EQ(SUPPORTS_END_TO_END, count);
1194 
1195   android_logger_list_close(logger_list);
1196 #else
1197   GTEST_LOG_(INFO) << "This test does nothing.\n";
1198 #endif
1199 }
1200 
TEST(liblog,too_big_payload)1201 TEST(liblog, too_big_payload) {
1202 #ifdef TEST_PREFIX
1203   TEST_PREFIX
1204   pid_t pid = getpid();
1205   static const char big_payload_tag[] = "TEST_big_payload_XXXX";
1206   char tag[sizeof(big_payload_tag)];
1207   memcpy(tag, big_payload_tag, sizeof(tag));
1208   snprintf(tag + sizeof(tag) - 5, 5, "%04X", pid & 0xFFFF);
1209 
1210   std::string longString(3266519, 'x');
1211 
1212   ssize_t ret = LOG_FAILURE_RETRY(__android_log_buf_write(
1213       LOG_ID_SYSTEM, ANDROID_LOG_INFO, tag, longString.c_str()));
1214 
1215   struct logger_list* logger_list;
1216 
1217   ASSERT_TRUE(NULL != (logger_list = android_logger_list_open(
1218                            LOG_ID_SYSTEM,
1219                            ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 100, 0)));
1220 
1221   ssize_t max_len = 0;
1222 
1223   for (;;) {
1224     log_msg log_msg;
1225     if (android_logger_list_read(logger_list, &log_msg) <= 0) {
1226       break;
1227     }
1228 
1229     if ((log_msg.entry.pid != pid) || (log_msg.id() != LOG_ID_SYSTEM)) {
1230       continue;
1231     }
1232 
1233     char* data = log_msg.msg();
1234 
1235     if (!data || strcmp(++data, tag)) {
1236       continue;
1237     }
1238 
1239     data += strlen(data) + 1;
1240 
1241     const char* left = data;
1242     const char* right = longString.c_str();
1243     while (*left && *right && (*left == *right)) {
1244       ++left;
1245       ++right;
1246     }
1247 
1248     if (max_len <= (left - data)) {
1249       max_len = left - data + 1;
1250     }
1251   }
1252 
1253   android_logger_list_close(logger_list);
1254 
1255 #if !SUPPORTS_END_TO_END
1256   max_len =
1257       max_len ? max_len : LOGGER_ENTRY_MAX_PAYLOAD - sizeof(big_payload_tag);
1258 #endif
1259   EXPECT_LE(LOGGER_ENTRY_MAX_PAYLOAD - sizeof(big_payload_tag),
1260             static_cast<size_t>(max_len));
1261 
1262   // SLOP: Allow the underlying interface to optionally place a
1263   // terminating nul at the LOGGER_ENTRY_MAX_PAYLOAD's last byte
1264   // or not.
1265   if (ret == (max_len + static_cast<ssize_t>(sizeof(big_payload_tag)) - 1)) {
1266     --max_len;
1267   }
1268   EXPECT_EQ(ret, max_len + static_cast<ssize_t>(sizeof(big_payload_tag)));
1269 #else
1270   GTEST_LOG_(INFO) << "This test does nothing.\n";
1271 #endif
1272 }
1273 
TEST(liblog,dual_reader)1274 TEST(liblog, dual_reader) {
1275 #ifdef TEST_PREFIX
1276   TEST_PREFIX
1277 
1278   static const int num = 25;
1279 
1280   for (int i = 25; i > 0; --i) {
1281     static const char fmt[] = "dual_reader %02d";
1282     char buffer[sizeof(fmt) + 8];
1283     snprintf(buffer, sizeof(buffer), fmt, i);
1284     LOG_FAILURE_RETRY(__android_log_buf_write(LOG_ID_MAIN, ANDROID_LOG_INFO,
1285                                               "liblog", buffer));
1286   }
1287   usleep(1000000);
1288 
1289   struct logger_list* logger_list1;
1290   ASSERT_TRUE(NULL != (logger_list1 = android_logger_list_open(
1291                            LOG_ID_MAIN,
1292                            ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, num, 0)));
1293 
1294   struct logger_list* logger_list2;
1295 
1296   if (NULL == (logger_list2 = android_logger_list_open(
1297                    LOG_ID_MAIN, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK,
1298                    num - 10, 0))) {
1299     android_logger_list_close(logger_list1);
1300     ASSERT_TRUE(NULL != logger_list2);
1301   }
1302 
1303   int count1 = 0;
1304   bool done1 = false;
1305   int count2 = 0;
1306   bool done2 = false;
1307 
1308   do {
1309     log_msg log_msg;
1310 
1311     if (!done1) {
1312       if (android_logger_list_read(logger_list1, &log_msg) <= 0) {
1313         done1 = true;
1314       } else {
1315         ++count1;
1316       }
1317     }
1318 
1319     if (!done2) {
1320       if (android_logger_list_read(logger_list2, &log_msg) <= 0) {
1321         done2 = true;
1322       } else {
1323         ++count2;
1324       }
1325     }
1326   } while ((!done1) || (!done2));
1327 
1328   android_logger_list_close(logger_list1);
1329   android_logger_list_close(logger_list2);
1330 
1331   EXPECT_EQ(num * SUPPORTS_END_TO_END, count1);
1332   EXPECT_EQ((num - 10) * SUPPORTS_END_TO_END, count2);
1333 #else
1334   GTEST_LOG_(INFO) << "This test does nothing.\n";
1335 #endif
1336 }
1337 
1338 #ifdef USING_LOGGER_DEFAULT  // Do not retest logprint
checkPriForTag(AndroidLogFormat * p_format,const char * tag,android_LogPriority pri)1339 static bool checkPriForTag(AndroidLogFormat* p_format, const char* tag,
1340                            android_LogPriority pri) {
1341   return android_log_shouldPrintLine(p_format, tag, pri) &&
1342          !android_log_shouldPrintLine(p_format, tag,
1343                                       (android_LogPriority)(pri - 1));
1344 }
1345 
TEST(liblog,filterRule)1346 TEST(liblog, filterRule) {
1347   static const char tag[] = "random";
1348 
1349   AndroidLogFormat* p_format = android_log_format_new();
1350 
1351   android_log_addFilterRule(p_format, "*:i");
1352 
1353   EXPECT_TRUE(checkPriForTag(p_format, tag, ANDROID_LOG_INFO));
1354   EXPECT_TRUE(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) ==
1355               0);
1356   android_log_addFilterRule(p_format, "*");
1357   EXPECT_TRUE(checkPriForTag(p_format, tag, ANDROID_LOG_DEBUG));
1358   EXPECT_TRUE(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) > 0);
1359   android_log_addFilterRule(p_format, "*:v");
1360   EXPECT_TRUE(checkPriForTag(p_format, tag, ANDROID_LOG_VERBOSE));
1361   EXPECT_TRUE(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) > 0);
1362   android_log_addFilterRule(p_format, "*:i");
1363   EXPECT_TRUE(checkPriForTag(p_format, tag, ANDROID_LOG_INFO));
1364   EXPECT_TRUE(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) ==
1365               0);
1366 
1367   android_log_addFilterRule(p_format, tag);
1368   EXPECT_TRUE(checkPriForTag(p_format, tag, ANDROID_LOG_VERBOSE));
1369   EXPECT_TRUE(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) > 0);
1370   android_log_addFilterRule(p_format, "random:v");
1371   EXPECT_TRUE(checkPriForTag(p_format, tag, ANDROID_LOG_VERBOSE));
1372   EXPECT_TRUE(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) > 0);
1373   android_log_addFilterRule(p_format, "random:d");
1374   EXPECT_TRUE(checkPriForTag(p_format, tag, ANDROID_LOG_DEBUG));
1375   EXPECT_TRUE(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) > 0);
1376   android_log_addFilterRule(p_format, "random:w");
1377   EXPECT_TRUE(checkPriForTag(p_format, tag, ANDROID_LOG_WARN));
1378   EXPECT_TRUE(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) ==
1379               0);
1380 
1381   android_log_addFilterRule(p_format, "crap:*");
1382   EXPECT_TRUE(checkPriForTag(p_format, "crap", ANDROID_LOG_VERBOSE));
1383   EXPECT_TRUE(
1384       android_log_shouldPrintLine(p_format, "crap", ANDROID_LOG_VERBOSE) > 0);
1385 
1386   // invalid expression
1387   EXPECT_TRUE(android_log_addFilterRule(p_format, "random:z") < 0);
1388   EXPECT_TRUE(checkPriForTag(p_format, tag, ANDROID_LOG_WARN));
1389   EXPECT_TRUE(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) ==
1390               0);
1391 
1392   // Issue #550946
1393   EXPECT_TRUE(android_log_addFilterString(p_format, " ") == 0);
1394   EXPECT_TRUE(checkPriForTag(p_format, tag, ANDROID_LOG_WARN));
1395 
1396   // note trailing space
1397   EXPECT_TRUE(android_log_addFilterString(p_format, "*:s random:d ") == 0);
1398   EXPECT_TRUE(checkPriForTag(p_format, tag, ANDROID_LOG_DEBUG));
1399 
1400   EXPECT_TRUE(android_log_addFilterString(p_format, "*:s random:z") < 0);
1401 
1402 #if 0  // bitrot, seek update
1403     char defaultBuffer[512];
1404 
1405     android_log_formatLogLine(p_format,
1406         defaultBuffer, sizeof(defaultBuffer), 0, ANDROID_LOG_ERROR, 123,
1407         123, 123, tag, "nofile", strlen("Hello"), "Hello", NULL);
1408 
1409     fprintf(stderr, "%s\n", defaultBuffer);
1410 #endif
1411 
1412   android_log_format_free(p_format);
1413 }
1414 #endif  // USING_LOGGER_DEFAULT
1415 
1416 #ifdef USING_LOGGER_DEFAULT  // Do not retest property handling
TEST(liblog,is_loggable)1417 TEST(liblog, is_loggable) {
1418 #ifdef __ANDROID__
1419   static const char tag[] = "is_loggable";
1420   static const char log_namespace[] = "persist.log.tag.";
1421   static const size_t base_offset = 8; /* skip "persist." */
1422   // sizeof("string") = strlen("string") + 1
1423   char key[sizeof(log_namespace) + sizeof(tag) - 1];
1424   char hold[4][PROP_VALUE_MAX];
1425   static const struct {
1426     int level;
1427     char type;
1428   } levels[] = {
1429     { ANDROID_LOG_VERBOSE, 'v' },
1430     { ANDROID_LOG_DEBUG, 'd' },
1431     { ANDROID_LOG_INFO, 'i' },
1432     { ANDROID_LOG_WARN, 'w' },
1433     { ANDROID_LOG_ERROR, 'e' },
1434     { ANDROID_LOG_FATAL, 'a' },
1435     { -1, 's' },
1436     { -2, 'g' },  // Illegal value, resort to default
1437   };
1438 
1439   // Set up initial test condition
1440   memset(hold, 0, sizeof(hold));
1441   snprintf(key, sizeof(key), "%s%s", log_namespace, tag);
1442   property_get(key, hold[0], "");
1443   property_set(key, "");
1444   property_get(key + base_offset, hold[1], "");
1445   property_set(key + base_offset, "");
1446   strcpy(key, log_namespace);
1447   key[sizeof(log_namespace) - 2] = '\0';
1448   property_get(key, hold[2], "");
1449   property_set(key, "");
1450   property_get(key, hold[3], "");
1451   property_set(key + base_offset, "");
1452 
1453   // All combinations of level and defaults
1454   for (size_t i = 0; i < (sizeof(levels) / sizeof(levels[0])); ++i) {
1455     if (levels[i].level == -2) {
1456       continue;
1457     }
1458     for (size_t j = 0; j < (sizeof(levels) / sizeof(levels[0])); ++j) {
1459       if (levels[j].level == -2) {
1460         continue;
1461       }
1462       fprintf(stderr, "i=%zu j=%zu\r", i, j);
1463       bool android_log_is_loggable = __android_log_is_loggable_len(
1464           levels[i].level, tag, strlen(tag), levels[j].level);
1465       if ((levels[i].level < levels[j].level) || (levels[j].level == -1)) {
1466         if (android_log_is_loggable) {
1467           fprintf(stderr, "\n");
1468         }
1469         EXPECT_FALSE(android_log_is_loggable);
1470         for (size_t k = 10; k; --k) {
1471           EXPECT_FALSE(__android_log_is_loggable_len(
1472               levels[i].level, tag, strlen(tag), levels[j].level));
1473         }
1474       } else {
1475         if (!android_log_is_loggable) {
1476           fprintf(stderr, "\n");
1477         }
1478         EXPECT_TRUE(android_log_is_loggable);
1479         for (size_t k = 10; k; --k) {
1480           EXPECT_TRUE(__android_log_is_loggable_len(
1481               levels[i].level, tag, strlen(tag), levels[j].level));
1482         }
1483       }
1484     }
1485   }
1486 
1487   // All combinations of level and tag and global properties
1488   for (size_t i = 0; i < (sizeof(levels) / sizeof(levels[0])); ++i) {
1489     if (levels[i].level == -2) {
1490       continue;
1491     }
1492     for (size_t j = 0; j < (sizeof(levels) / sizeof(levels[0])); ++j) {
1493       char buf[2];
1494       buf[0] = levels[j].type;
1495       buf[1] = '\0';
1496 
1497       snprintf(key, sizeof(key), "%s%s", log_namespace, tag);
1498       fprintf(stderr, "i=%zu j=%zu property_set(\"%s\",\"%s\")\r", i, j, key,
1499               buf);
1500       usleep(20000);
1501       property_set(key, buf);
1502       bool android_log_is_loggable = __android_log_is_loggable_len(
1503           levels[i].level, tag, strlen(tag), ANDROID_LOG_DEBUG);
1504       if ((levels[i].level < levels[j].level) || (levels[j].level == -1) ||
1505           ((levels[i].level < ANDROID_LOG_DEBUG) && (levels[j].level == -2))) {
1506         if (android_log_is_loggable) {
1507           fprintf(stderr, "\n");
1508         }
1509         EXPECT_FALSE(android_log_is_loggable);
1510         for (size_t k = 10; k; --k) {
1511           EXPECT_FALSE(__android_log_is_loggable_len(
1512               levels[i].level, tag, strlen(tag), ANDROID_LOG_DEBUG));
1513         }
1514       } else {
1515         if (!android_log_is_loggable) {
1516           fprintf(stderr, "\n");
1517         }
1518         EXPECT_TRUE(android_log_is_loggable);
1519         for (size_t k = 10; k; --k) {
1520           EXPECT_TRUE(__android_log_is_loggable_len(
1521               levels[i].level, tag, strlen(tag), ANDROID_LOG_DEBUG));
1522         }
1523       }
1524       usleep(20000);
1525       property_set(key, "");
1526 
1527       fprintf(stderr, "i=%zu j=%zu property_set(\"%s\",\"%s\")\r", i, j,
1528               key + base_offset, buf);
1529       property_set(key + base_offset, buf);
1530       android_log_is_loggable = __android_log_is_loggable_len(
1531           levels[i].level, tag, strlen(tag), ANDROID_LOG_DEBUG);
1532       if ((levels[i].level < levels[j].level) || (levels[j].level == -1) ||
1533           ((levels[i].level < ANDROID_LOG_DEBUG) && (levels[j].level == -2))) {
1534         if (android_log_is_loggable) {
1535           fprintf(stderr, "\n");
1536         }
1537         EXPECT_FALSE(android_log_is_loggable);
1538         for (size_t k = 10; k; --k) {
1539           EXPECT_FALSE(__android_log_is_loggable_len(
1540               levels[i].level, tag, strlen(tag), ANDROID_LOG_DEBUG));
1541         }
1542       } else {
1543         if (!android_log_is_loggable) {
1544           fprintf(stderr, "\n");
1545         }
1546         EXPECT_TRUE(android_log_is_loggable);
1547         for (size_t k = 10; k; --k) {
1548           EXPECT_TRUE(__android_log_is_loggable_len(
1549               levels[i].level, tag, strlen(tag), ANDROID_LOG_DEBUG));
1550         }
1551       }
1552       usleep(20000);
1553       property_set(key + base_offset, "");
1554 
1555       strcpy(key, log_namespace);
1556       key[sizeof(log_namespace) - 2] = '\0';
1557       fprintf(stderr, "i=%zu j=%zu property_set(\"%s\",\"%s\")\r", i, j, key,
1558               buf);
1559       property_set(key, buf);
1560       android_log_is_loggable = __android_log_is_loggable_len(
1561           levels[i].level, tag, strlen(tag), ANDROID_LOG_DEBUG);
1562       if ((levels[i].level < levels[j].level) || (levels[j].level == -1) ||
1563           ((levels[i].level < ANDROID_LOG_DEBUG) && (levels[j].level == -2))) {
1564         if (android_log_is_loggable) {
1565           fprintf(stderr, "\n");
1566         }
1567         EXPECT_FALSE(android_log_is_loggable);
1568         for (size_t k = 10; k; --k) {
1569           EXPECT_FALSE(__android_log_is_loggable_len(
1570               levels[i].level, tag, strlen(tag), ANDROID_LOG_DEBUG));
1571         }
1572       } else {
1573         if (!android_log_is_loggable) {
1574           fprintf(stderr, "\n");
1575         }
1576         EXPECT_TRUE(android_log_is_loggable);
1577         for (size_t k = 10; k; --k) {
1578           EXPECT_TRUE(__android_log_is_loggable_len(
1579               levels[i].level, tag, strlen(tag), ANDROID_LOG_DEBUG));
1580         }
1581       }
1582       usleep(20000);
1583       property_set(key, "");
1584 
1585       fprintf(stderr, "i=%zu j=%zu property_set(\"%s\",\"%s\")\r", i, j,
1586               key + base_offset, buf);
1587       property_set(key + base_offset, buf);
1588       android_log_is_loggable = __android_log_is_loggable_len(
1589           levels[i].level, tag, strlen(tag), ANDROID_LOG_DEBUG);
1590       if ((levels[i].level < levels[j].level) || (levels[j].level == -1) ||
1591           ((levels[i].level < ANDROID_LOG_DEBUG) && (levels[j].level == -2))) {
1592         if (android_log_is_loggable) {
1593           fprintf(stderr, "\n");
1594         }
1595         EXPECT_FALSE(android_log_is_loggable);
1596         for (size_t k = 10; k; --k) {
1597           EXPECT_FALSE(__android_log_is_loggable_len(
1598               levels[i].level, tag, strlen(tag), ANDROID_LOG_DEBUG));
1599         }
1600       } else {
1601         if (!android_log_is_loggable) {
1602           fprintf(stderr, "\n");
1603         }
1604         EXPECT_TRUE(android_log_is_loggable);
1605         for (size_t k = 10; k; --k) {
1606           EXPECT_TRUE(__android_log_is_loggable_len(
1607               levels[i].level, tag, strlen(tag), ANDROID_LOG_DEBUG));
1608         }
1609       }
1610       usleep(20000);
1611       property_set(key + base_offset, "");
1612     }
1613   }
1614 
1615   // All combinations of level and tag properties, but with global set to INFO
1616   strcpy(key, log_namespace);
1617   key[sizeof(log_namespace) - 2] = '\0';
1618   usleep(20000);
1619   property_set(key, "I");
1620   snprintf(key, sizeof(key), "%s%s", log_namespace, tag);
1621   for (size_t i = 0; i < (sizeof(levels) / sizeof(levels[0])); ++i) {
1622     if (levels[i].level == -2) {
1623       continue;
1624     }
1625     for (size_t j = 0; j < (sizeof(levels) / sizeof(levels[0])); ++j) {
1626       char buf[2];
1627       buf[0] = levels[j].type;
1628       buf[1] = '\0';
1629 
1630       fprintf(stderr, "i=%zu j=%zu property_set(\"%s\",\"%s\")\r", i, j, key,
1631               buf);
1632       usleep(20000);
1633       property_set(key, buf);
1634       bool android_log_is_loggable = __android_log_is_loggable_len(
1635           levels[i].level, tag, strlen(tag), ANDROID_LOG_DEBUG);
1636       if ((levels[i].level < levels[j].level) || (levels[j].level == -1) ||
1637           ((levels[i].level < ANDROID_LOG_INFO)  // Yes INFO
1638            && (levels[j].level == -2))) {
1639         if (android_log_is_loggable) {
1640           fprintf(stderr, "\n");
1641         }
1642         EXPECT_FALSE(android_log_is_loggable);
1643         for (size_t k = 10; k; --k) {
1644           EXPECT_FALSE(__android_log_is_loggable_len(
1645               levels[i].level, tag, strlen(tag), ANDROID_LOG_DEBUG));
1646         }
1647       } else {
1648         if (!android_log_is_loggable) {
1649           fprintf(stderr, "\n");
1650         }
1651         EXPECT_TRUE(android_log_is_loggable);
1652         for (size_t k = 10; k; --k) {
1653           EXPECT_TRUE(__android_log_is_loggable_len(
1654               levels[i].level, tag, strlen(tag), ANDROID_LOG_DEBUG));
1655         }
1656       }
1657       usleep(20000);
1658       property_set(key, "");
1659 
1660       fprintf(stderr, "i=%zu j=%zu property_set(\"%s\",\"%s\")\r", i, j,
1661               key + base_offset, buf);
1662       property_set(key + base_offset, buf);
1663       android_log_is_loggable = __android_log_is_loggable_len(
1664           levels[i].level, tag, strlen(tag), ANDROID_LOG_DEBUG);
1665       if ((levels[i].level < levels[j].level) || (levels[j].level == -1) ||
1666           ((levels[i].level < ANDROID_LOG_INFO)  // Yes INFO
1667            && (levels[j].level == -2))) {
1668         if (android_log_is_loggable) {
1669           fprintf(stderr, "\n");
1670         }
1671         EXPECT_FALSE(android_log_is_loggable);
1672         for (size_t k = 10; k; --k) {
1673           EXPECT_FALSE(__android_log_is_loggable_len(
1674               levels[i].level, tag, strlen(tag), ANDROID_LOG_DEBUG));
1675         }
1676       } else {
1677         if (!android_log_is_loggable) {
1678           fprintf(stderr, "\n");
1679         }
1680         EXPECT_TRUE(android_log_is_loggable);
1681         for (size_t k = 10; k; --k) {
1682           EXPECT_TRUE(__android_log_is_loggable_len(
1683               levels[i].level, tag, strlen(tag), ANDROID_LOG_DEBUG));
1684         }
1685       }
1686       usleep(20000);
1687       property_set(key + base_offset, "");
1688     }
1689   }
1690 
1691   // reset parms
1692   snprintf(key, sizeof(key), "%s%s", log_namespace, tag);
1693   usleep(20000);
1694   property_set(key, hold[0]);
1695   property_set(key + base_offset, hold[1]);
1696   strcpy(key, log_namespace);
1697   key[sizeof(log_namespace) - 2] = '\0';
1698   property_set(key, hold[2]);
1699   property_set(key + base_offset, hold[3]);
1700 #else
1701   GTEST_LOG_(INFO) << "This test does nothing.\n";
1702 #endif
1703 }
1704 #endif  // USING_LOGGER_DEFAULT
1705 
1706 // Following tests the specific issues surrounding error handling wrt logd.
1707 // Kills logd and toss all collected data, equivalent to logcat -b all -c,
1708 // except we also return errors to the logging callers.
1709 #ifdef USING_LOGGER_DEFAULT
1710 #ifdef __ANDROID__
1711 #ifdef TEST_PREFIX
1712 // helper to liblog.enoent to count end-to-end matching logging messages.
count_matching_ts(log_time ts)1713 static int count_matching_ts(log_time ts) {
1714   usleep(1000000);
1715 
1716   pid_t pid = getpid();
1717 
1718   struct logger_list* logger_list = android_logger_list_open(
1719       LOG_ID_EVENTS, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 1000, pid);
1720 
1721   int count = 0;
1722   if (logger_list == NULL) return count;
1723 
1724   for (;;) {
1725     log_msg log_msg;
1726     if (android_logger_list_read(logger_list, &log_msg) <= 0) break;
1727 
1728     if (log_msg.entry.len != sizeof(android_log_event_long_t)) continue;
1729     if (log_msg.id() != LOG_ID_EVENTS) continue;
1730 
1731     android_log_event_long_t* eventData;
1732     eventData = reinterpret_cast<android_log_event_long_t*>(log_msg.msg());
1733     if (!eventData) continue;
1734     if (eventData->payload.type != EVENT_TYPE_LONG) continue;
1735 
1736     log_time tx(reinterpret_cast<char*>(&eventData->payload.data));
1737     if (ts != tx) continue;
1738 
1739     // found event message with matching timestamp signature in payload
1740     ++count;
1741   }
1742   android_logger_list_close(logger_list);
1743 
1744   return count;
1745 }
1746 
1747 // meant to be handed to ASSERT_TRUE / EXPECT_TRUE only to expand the message
IsOk(bool ok,std::string & message)1748 static testing::AssertionResult IsOk(bool ok, std::string& message) {
1749   return ok ? testing::AssertionSuccess()
1750             : (testing::AssertionFailure() << message);
1751 }
1752 #endif  // TEST_PREFIX
1753 
TEST(liblog,enoent)1754 TEST(liblog, enoent) {
1755 #ifdef TEST_PREFIX
1756   TEST_PREFIX
1757   log_time ts(CLOCK_MONOTONIC);
1758   EXPECT_LT(0, __android_log_btwrite(0, EVENT_TYPE_LONG, &ts, sizeof(ts)));
1759   EXPECT_EQ(SUPPORTS_END_TO_END, count_matching_ts(ts));
1760 
1761   // This call will fail if we are setuid(AID_SYSTEM), beware of any
1762   // test prior to this one playing with setuid and causing interference.
1763   // We need to run before these tests so that they do not interfere with
1764   // this test.
1765   //
1766   // Stopping the logger can affect some other test's expectations as they
1767   // count on the log buffers filled with existing content, and this
1768   // effectively does a logcat -c emptying it.  So we want this test to be
1769   // as near as possible to the bottom of the file.  For example
1770   // liblog.android_logger_get_ is one of those tests that has no recourse
1771   // and that would be adversely affected by emptying the log if it was run
1772   // right after this test.
1773   if (getuid() != AID_ROOT) {
1774     fprintf(
1775         stderr,
1776         "WARNING: test conditions request being run as root and not AID=%d\n",
1777         getuid());
1778     if (!__android_log_is_debuggable()) {
1779       fprintf(
1780           stderr,
1781           "WARNING: can not run test on a \"user\" build, bypassing test\n");
1782       return;
1783     }
1784   }
1785 
1786   system((getuid() == AID_ROOT) ? "stop logd" : "su 0 stop logd");
1787   usleep(1000000);
1788 
1789   // A clean stop like we are testing returns -ENOENT, but in the _real_
1790   // world we could get -ENOTCONN or -ECONNREFUSED depending on timing.
1791   // Alas we can not test these other return values; accept that they
1792   // are treated equally within the open-retry logic in liblog.
1793   ts = log_time(CLOCK_MONOTONIC);
1794   int ret = __android_log_btwrite(0, EVENT_TYPE_LONG, &ts, sizeof(ts));
1795   std::string content = android::base::StringPrintf(
1796       "__android_log_btwrite(0, EVENT_TYPE_LONG, &ts, sizeof(ts)) = %d %s\n",
1797       ret, (ret <= 0) ? strerror(-ret) : "(content sent)");
1798   EXPECT_TRUE(
1799       IsOk((ret == -ENOENT) || (ret == -ENOTCONN) || (ret == -ECONNREFUSED),
1800            content));
1801   ret = __android_log_btwrite(0, EVENT_TYPE_LONG, &ts, sizeof(ts));
1802   content = android::base::StringPrintf(
1803       "__android_log_btwrite(0, EVENT_TYPE_LONG, &ts, sizeof(ts)) = %d %s\n",
1804       ret, (ret <= 0) ? strerror(-ret) : "(content sent)");
1805   EXPECT_TRUE(
1806       IsOk((ret == -ENOENT) || (ret == -ENOTCONN) || (ret == -ECONNREFUSED),
1807            content));
1808   EXPECT_EQ(0, count_matching_ts(ts));
1809 
1810   system((getuid() == AID_ROOT) ? "start logd" : "su 0 start logd");
1811   usleep(1000000);
1812 
1813   EXPECT_EQ(0, count_matching_ts(ts));
1814 
1815   ts = log_time(CLOCK_MONOTONIC);
1816   EXPECT_LT(0, __android_log_btwrite(0, EVENT_TYPE_LONG, &ts, sizeof(ts)));
1817   EXPECT_EQ(SUPPORTS_END_TO_END, count_matching_ts(ts));
1818 
1819 #else
1820   GTEST_LOG_(INFO) << "This test does nothing.\n";
1821 #endif
1822 }
1823 #endif  // __ANDROID__
1824 #endif  // USING_LOGGER_DEFAULT
1825 
1826 // Below this point we run risks of setuid(AID_SYSTEM) which may affect others.
1827 
1828 // Do not retest properties, and cannot log into LOG_ID_SECURITY
1829 #ifdef USING_LOGGER_DEFAULT
TEST(liblog,__security)1830 TEST(liblog, __security) {
1831 #ifdef __ANDROID__
1832   static const char persist_key[] = "persist.logd.security";
1833   static const char readonly_key[] = "ro.device_owner";
1834   // A silly default value that can never be in readonly_key so
1835   // that it can be determined the property is not set.
1836   static const char nothing_val[] = "_NOTHING_TO_SEE_HERE_";
1837   char persist[PROP_VALUE_MAX];
1838   char persist_hold[PROP_VALUE_MAX];
1839   char readonly[PROP_VALUE_MAX];
1840 
1841   // First part of this test requires the test itself to have the appropriate
1842   // permissions. If we do not have them, we can not override them, so we
1843   // bail rather than give a failing grade.
1844   property_get(persist_key, persist, "");
1845   fprintf(stderr, "INFO: getprop %s -> %s\n", persist_key, persist);
1846   strncpy(persist_hold, persist, PROP_VALUE_MAX);
1847   property_get(readonly_key, readonly, nothing_val);
1848   fprintf(stderr, "INFO: getprop %s -> %s\n", readonly_key, readonly);
1849 
1850   if (!strcmp(readonly, nothing_val)) {
1851     // Lets check if we can set the value (we should not be allowed to do so)
1852     EXPECT_FALSE(__android_log_security());
1853     fprintf(stderr, "WARNING: setting ro.device_owner to a domain\n");
1854     static const char domain[] = "com.google.android.SecOps.DeviceOwner";
1855     EXPECT_NE(0, property_set(readonly_key, domain));
1856     useconds_t total_time = 0;
1857     static const useconds_t seconds = 1000000;
1858     static const useconds_t max_time = 5 * seconds;  // not going to happen
1859     static const useconds_t rest = 20 * 1000;
1860     for (; total_time < max_time; total_time += rest) {
1861       usleep(rest);  // property system does not guarantee performance.
1862       property_get(readonly_key, readonly, nothing_val);
1863       if (!strcmp(readonly, domain)) {
1864         if (total_time > rest) {
1865           fprintf(stderr, "INFO: took %u.%06u seconds to set property\n",
1866                   (unsigned)(total_time / seconds),
1867                   (unsigned)(total_time % seconds));
1868         }
1869         break;
1870       }
1871     }
1872     EXPECT_STRNE(domain, readonly);
1873   }
1874 
1875   if (!strcasecmp(readonly, "false") || !readonly[0] ||
1876       !strcmp(readonly, nothing_val)) {
1877     // not enough permissions to run tests surrounding persist.logd.security
1878     EXPECT_FALSE(__android_log_security());
1879     return;
1880   }
1881 
1882   if (!strcasecmp(persist, "true")) {
1883     EXPECT_TRUE(__android_log_security());
1884   } else {
1885     EXPECT_FALSE(__android_log_security());
1886   }
1887   property_set(persist_key, "TRUE");
1888   property_get(persist_key, persist, "");
1889   uid_t uid = getuid();
1890   gid_t gid = getgid();
1891   bool perm = (gid == AID_ROOT) || (uid == AID_ROOT);
1892   EXPECT_STREQ(perm ? "TRUE" : persist_hold, persist);
1893   if (!strcasecmp(persist, "true")) {
1894     EXPECT_TRUE(__android_log_security());
1895   } else {
1896     EXPECT_FALSE(__android_log_security());
1897   }
1898   property_set(persist_key, "FALSE");
1899   property_get(persist_key, persist, "");
1900   EXPECT_STREQ(perm ? "FALSE" : persist_hold, persist);
1901   if (!strcasecmp(persist, "true")) {
1902     EXPECT_TRUE(__android_log_security());
1903   } else {
1904     EXPECT_FALSE(__android_log_security());
1905   }
1906   property_set(persist_key, "true");
1907   property_get(persist_key, persist, "");
1908   EXPECT_STREQ(perm ? "true" : persist_hold, persist);
1909   if (!strcasecmp(persist, "true")) {
1910     EXPECT_TRUE(__android_log_security());
1911   } else {
1912     EXPECT_FALSE(__android_log_security());
1913   }
1914   property_set(persist_key, "false");
1915   property_get(persist_key, persist, "");
1916   EXPECT_STREQ(perm ? "false" : persist_hold, persist);
1917   if (!strcasecmp(persist, "true")) {
1918     EXPECT_TRUE(__android_log_security());
1919   } else {
1920     EXPECT_FALSE(__android_log_security());
1921   }
1922   property_set(persist_key, "");
1923   property_get(persist_key, persist, "");
1924   EXPECT_STREQ(perm ? "" : persist_hold, persist);
1925   if (!strcasecmp(persist, "true")) {
1926     EXPECT_TRUE(__android_log_security());
1927   } else {
1928     EXPECT_FALSE(__android_log_security());
1929   }
1930   property_set(persist_key, persist_hold);
1931   property_get(persist_key, persist, "");
1932   EXPECT_STREQ(persist_hold, persist);
1933 #else
1934   GTEST_LOG_(INFO) << "This test does nothing.\n";
1935 #endif
1936 }
1937 
TEST(liblog,__security_buffer)1938 TEST(liblog, __security_buffer) {
1939 #ifdef __ANDROID__
1940   struct logger_list* logger_list;
1941   android_event_long_t buffer;
1942 
1943   static const char persist_key[] = "persist.logd.security";
1944   char persist[PROP_VALUE_MAX];
1945   bool set_persist = false;
1946   bool allow_security = false;
1947 
1948   if (__android_log_security()) {
1949     allow_security = true;
1950   } else {
1951     property_get(persist_key, persist, "");
1952     if (strcasecmp(persist, "true")) {
1953       property_set(persist_key, "TRUE");
1954       if (__android_log_security()) {
1955         allow_security = true;
1956         set_persist = true;
1957       } else {
1958         property_set(persist_key, persist);
1959       }
1960     }
1961   }
1962 
1963   if (!allow_security) {
1964     fprintf(stderr,
1965             "WARNING: "
1966             "security buffer disabled, bypassing end-to-end test\n");
1967 
1968     log_time ts(CLOCK_MONOTONIC);
1969 
1970     buffer.type = EVENT_TYPE_LONG;
1971     buffer.data = *(static_cast<uint64_t*>((void*)&ts));
1972 
1973     // expect failure!
1974     ASSERT_GE(0, __android_log_security_bwrite(0, &buffer, sizeof(buffer)));
1975 
1976     return;
1977   }
1978 
1979   /* Matches clientHasLogCredentials() in logd */
1980   uid_t uid = getuid();
1981   gid_t gid = getgid();
1982   bool clientHasLogCredentials = true;
1983   if ((uid != AID_SYSTEM) && (uid != AID_ROOT) && (uid != AID_LOG) &&
1984       (gid != AID_SYSTEM) && (gid != AID_ROOT) && (gid != AID_LOG)) {
1985     uid_t euid = geteuid();
1986     if ((euid != AID_SYSTEM) && (euid != AID_ROOT) && (euid != AID_LOG)) {
1987       gid_t egid = getegid();
1988       if ((egid != AID_SYSTEM) && (egid != AID_ROOT) && (egid != AID_LOG)) {
1989         int num_groups = getgroups(0, NULL);
1990         if (num_groups > 0) {
1991           gid_t groups[num_groups];
1992           num_groups = getgroups(num_groups, groups);
1993           while (num_groups > 0) {
1994             if (groups[num_groups - 1] == AID_LOG) {
1995               break;
1996             }
1997             --num_groups;
1998           }
1999         }
2000         if (num_groups <= 0) {
2001           clientHasLogCredentials = false;
2002         }
2003       }
2004     }
2005   }
2006   if (!clientHasLogCredentials) {
2007     fprintf(stderr,
2008             "WARNING: "
2009             "not in system context, bypassing end-to-end test\n");
2010 
2011     log_time ts(CLOCK_MONOTONIC);
2012 
2013     buffer.type = EVENT_TYPE_LONG;
2014     buffer.data = *(static_cast<uint64_t*>((void*)&ts));
2015 
2016     // expect failure!
2017     ASSERT_GE(0, __android_log_security_bwrite(0, &buffer, sizeof(buffer)));
2018 
2019     return;
2020   }
2021 
2022   EXPECT_EQ(0, setuid(AID_SYSTEM));  // only one that can read security buffer
2023 
2024   uid = getuid();
2025   gid = getgid();
2026   pid_t pid = getpid();
2027 
2028   ASSERT_TRUE(NULL !=
2029               (logger_list = android_logger_list_open(
2030                    LOG_ID_SECURITY, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK,
2031                    1000, pid)));
2032 
2033   log_time ts(CLOCK_MONOTONIC);
2034 
2035   buffer.type = EVENT_TYPE_LONG;
2036   buffer.data = *(static_cast<uint64_t*>((void*)&ts));
2037 
2038   ASSERT_LT(0, __android_log_security_bwrite(0, &buffer, sizeof(buffer)));
2039   usleep(1000000);
2040 
2041   int count = 0;
2042 
2043   for (;;) {
2044     log_msg log_msg;
2045     if (android_logger_list_read(logger_list, &log_msg) <= 0) {
2046       break;
2047     }
2048 
2049     ASSERT_EQ(log_msg.entry.pid, pid);
2050 
2051     if ((log_msg.entry.len != sizeof(android_log_event_long_t)) ||
2052         (log_msg.id() != LOG_ID_SECURITY)) {
2053       continue;
2054     }
2055 
2056     android_log_event_long_t* eventData;
2057     eventData = reinterpret_cast<android_log_event_long_t*>(log_msg.msg());
2058 
2059     if (!eventData || (eventData->payload.type != EVENT_TYPE_LONG)) {
2060       continue;
2061     }
2062 
2063     log_time tx(reinterpret_cast<char*>(&eventData->payload.data));
2064     if (ts == tx) {
2065       ++count;
2066     }
2067   }
2068 
2069   if (set_persist) {
2070     property_set(persist_key, persist);
2071   }
2072 
2073   android_logger_list_close(logger_list);
2074 
2075   bool clientHasSecurityCredentials = (uid == AID_SYSTEM) || (gid == AID_SYSTEM);
2076   if (!clientHasSecurityCredentials) {
2077     fprintf(stderr,
2078             "WARNING: "
2079             "not system, content submitted but can not check end-to-end\n");
2080   }
2081   EXPECT_EQ(clientHasSecurityCredentials ? 1 : 0, count);
2082 #else
2083   GTEST_LOG_(INFO) << "This test does nothing.\n";
2084 #endif
2085 }
2086 #endif  // USING_LOGGER_DEFAULT
2087 
2088 #ifdef TEST_PREFIX
android_errorWriteWithInfoLog_helper(int TAG,const char * SUBTAG,int UID,const char * payload,int DATA_LEN,int & count)2089 static void android_errorWriteWithInfoLog_helper(int TAG, const char* SUBTAG,
2090                                                  int UID, const char* payload,
2091                                                  int DATA_LEN, int& count) {
2092   TEST_PREFIX
2093   struct logger_list* logger_list;
2094 
2095   pid_t pid = getpid();
2096 
2097   count = 0;
2098 
2099   ASSERT_TRUE(NULL !=
2100               (logger_list = android_logger_list_open(
2101                    LOG_ID_EVENTS, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK,
2102                    1000, pid)));
2103 
2104   int retval_android_errorWriteWithinInfoLog =
2105       android_errorWriteWithInfoLog(TAG, SUBTAG, UID, payload, DATA_LEN);
2106   if (payload) {
2107     ASSERT_LT(0, retval_android_errorWriteWithinInfoLog);
2108   } else {
2109     ASSERT_GT(0, retval_android_errorWriteWithinInfoLog);
2110   }
2111 
2112   sleep(2);
2113 
2114   for (;;) {
2115     log_msg log_msg;
2116     if (android_logger_list_read(logger_list, &log_msg) <= 0) {
2117       break;
2118     }
2119 
2120     char* eventData = log_msg.msg();
2121     if (!eventData) {
2122       continue;
2123     }
2124 
2125     char* original = eventData;
2126 
2127     // Tag
2128     int tag = get4LE(eventData);
2129     eventData += 4;
2130 
2131     if (tag != TAG) {
2132       continue;
2133     }
2134 
2135     if (!payload) {
2136       // This tag should not have been written because the data was null
2137       ++count;
2138       break;
2139     }
2140 
2141     // List type
2142     ASSERT_EQ(EVENT_TYPE_LIST, eventData[0]);
2143     eventData++;
2144 
2145     // Number of elements in list
2146     ASSERT_EQ(3, eventData[0]);
2147     eventData++;
2148 
2149     // Element #1: string type for subtag
2150     ASSERT_EQ(EVENT_TYPE_STRING, eventData[0]);
2151     eventData++;
2152 
2153     unsigned subtag_len = strlen(SUBTAG);
2154     if (subtag_len > 32) subtag_len = 32;
2155     ASSERT_EQ(subtag_len, get4LE(eventData));
2156     eventData += 4;
2157 
2158     if (memcmp(SUBTAG, eventData, subtag_len)) {
2159       continue;
2160     }
2161     eventData += subtag_len;
2162 
2163     // Element #2: int type for uid
2164     ASSERT_EQ(EVENT_TYPE_INT, eventData[0]);
2165     eventData++;
2166 
2167     ASSERT_EQ(UID, (int)get4LE(eventData));
2168     eventData += 4;
2169 
2170     // Element #3: string type for data
2171     ASSERT_EQ(EVENT_TYPE_STRING, eventData[0]);
2172     eventData++;
2173 
2174     size_t dataLen = get4LE(eventData);
2175     eventData += 4;
2176     if (DATA_LEN < 512) ASSERT_EQ(DATA_LEN, (int)dataLen);
2177 
2178     if (memcmp(payload, eventData, dataLen)) {
2179       continue;
2180     }
2181 
2182     if (DATA_LEN >= 512) {
2183       eventData += dataLen;
2184       // 4 bytes for the tag, and max_payload_buf should be truncated.
2185       ASSERT_LE(4 + 512, eventData - original);       // worst expectations
2186       ASSERT_GT(4 + DATA_LEN, eventData - original);  // must be truncated
2187     }
2188 
2189     ++count;
2190   }
2191 
2192   android_logger_list_close(logger_list);
2193 }
2194 #endif
2195 
2196 // Make multiple tests and re-tests orthogonal to prevent falsing.
2197 #ifdef TEST_LOGGER
2198 #define UNIQUE_TAG(X) \
2199   (0x12340000 + (((X) + sizeof(int) + sizeof(void*)) << 8) + TEST_LOGGER)
2200 #else
2201 #define UNIQUE_TAG(X) \
2202   (0x12340000 + (((X) + sizeof(int) + sizeof(void*)) << 8) + 0xBA)
2203 #endif
2204 
TEST(liblog,android_errorWriteWithInfoLog__android_logger_list_read__typical)2205 TEST(liblog, android_errorWriteWithInfoLog__android_logger_list_read__typical) {
2206 #ifdef TEST_PREFIX
2207   int count;
2208   android_errorWriteWithInfoLog_helper(UNIQUE_TAG(1), "test-subtag", -1,
2209                                        max_payload_buf, 200, count);
2210   EXPECT_EQ(SUPPORTS_END_TO_END, count);
2211 #else
2212   GTEST_LOG_(INFO) << "This test does nothing.\n";
2213 #endif
2214 }
2215 
TEST(liblog,android_errorWriteWithInfoLog__android_logger_list_read__data_too_large)2216 TEST(liblog,
2217      android_errorWriteWithInfoLog__android_logger_list_read__data_too_large) {
2218 #ifdef TEST_PREFIX
2219   int count;
2220   android_errorWriteWithInfoLog_helper(UNIQUE_TAG(2), "test-subtag", -1,
2221                                        max_payload_buf, sizeof(max_payload_buf),
2222                                        count);
2223   EXPECT_EQ(SUPPORTS_END_TO_END, count);
2224 #else
2225   GTEST_LOG_(INFO) << "This test does nothing.\n";
2226 #endif
2227 }
2228 
TEST(liblog,android_errorWriteWithInfoLog__android_logger_list_read__null_data)2229 TEST(liblog,
2230      android_errorWriteWithInfoLog__android_logger_list_read__null_data) {
2231 #ifdef TEST_PREFIX
2232   int count;
2233   android_errorWriteWithInfoLog_helper(UNIQUE_TAG(3), "test-subtag", -1, NULL,
2234                                        200, count);
2235   EXPECT_EQ(0, count);
2236 #else
2237   GTEST_LOG_(INFO) << "This test does nothing.\n";
2238 #endif
2239 }
2240 
TEST(liblog,android_errorWriteWithInfoLog__android_logger_list_read__subtag_too_long)2241 TEST(liblog,
2242      android_errorWriteWithInfoLog__android_logger_list_read__subtag_too_long) {
2243 #ifdef TEST_PREFIX
2244   int count;
2245   android_errorWriteWithInfoLog_helper(
2246       UNIQUE_TAG(4), "abcdefghijklmnopqrstuvwxyz now i know my abc", -1,
2247       max_payload_buf, 200, count);
2248   EXPECT_EQ(SUPPORTS_END_TO_END, count);
2249 #else
2250   GTEST_LOG_(INFO) << "This test does nothing.\n";
2251 #endif
2252 }
2253 
TEST(liblog,__android_log_bswrite_and_print___max)2254 TEST(liblog, __android_log_bswrite_and_print___max) {
2255   bswrite_test(max_payload_buf);
2256 }
2257 
TEST(liblog,__android_log_buf_write_and_print__max)2258 TEST(liblog, __android_log_buf_write_and_print__max) {
2259   buf_write_test(max_payload_buf);
2260 }
2261 
2262 #ifdef TEST_PREFIX
android_errorWriteLog_helper(int TAG,const char * SUBTAG,int & count)2263 static void android_errorWriteLog_helper(int TAG, const char* SUBTAG,
2264                                          int& count) {
2265   TEST_PREFIX
2266   struct logger_list* logger_list;
2267 
2268   pid_t pid = getpid();
2269 
2270   count = 0;
2271 
2272   // Do a Before and After on the count to measure the effect. Decrement
2273   // what we find in Before to set the stage.
2274   ASSERT_TRUE(NULL !=
2275               (logger_list = android_logger_list_open(
2276                    LOG_ID_EVENTS, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK,
2277                    1000, pid)));
2278 
2279   for (;;) {
2280     log_msg log_msg;
2281     if (android_logger_list_read(logger_list, &log_msg) <= 0) break;
2282 
2283     char* eventData = log_msg.msg();
2284     if (!eventData) continue;
2285 
2286     // Tag
2287     int tag = get4LE(eventData);
2288     eventData += 4;
2289 
2290     if (tag != TAG) continue;
2291 
2292     if (!SUBTAG) {
2293       // This tag should not have been written because the data was null
2294       --count;
2295       break;
2296     }
2297 
2298     // List type
2299     eventData++;
2300     // Number of elements in list
2301     eventData++;
2302     // Element #1: string type for subtag
2303     eventData++;
2304 
2305     eventData += 4;
2306 
2307     if (memcmp(SUBTAG, eventData, strlen(SUBTAG))) continue;
2308     --count;
2309   }
2310 
2311   android_logger_list_close(logger_list);
2312 
2313   // Do an After on the count to measure the effect.
2314   ASSERT_TRUE(NULL !=
2315               (logger_list = android_logger_list_open(
2316                    LOG_ID_EVENTS, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK,
2317                    1000, pid)));
2318 
2319   int retval_android_errorWriteLog = android_errorWriteLog(TAG, SUBTAG);
2320   if (SUBTAG) {
2321     ASSERT_LT(0, retval_android_errorWriteLog);
2322   } else {
2323     ASSERT_GT(0, retval_android_errorWriteLog);
2324   }
2325 
2326   sleep(2);
2327 
2328   for (;;) {
2329     log_msg log_msg;
2330     if (android_logger_list_read(logger_list, &log_msg) <= 0) {
2331       break;
2332     }
2333 
2334     char* eventData = log_msg.msg();
2335     if (!eventData) {
2336       continue;
2337     }
2338 
2339     // Tag
2340     int tag = get4LE(eventData);
2341     eventData += 4;
2342 
2343     if (tag != TAG) {
2344       continue;
2345     }
2346 
2347     if (!SUBTAG) {
2348       // This tag should not have been written because the data was null
2349       ++count;
2350       break;
2351     }
2352 
2353     // List type
2354     ASSERT_EQ(EVENT_TYPE_LIST, eventData[0]);
2355     eventData++;
2356 
2357     // Number of elements in list
2358     ASSERT_EQ(3, eventData[0]);
2359     eventData++;
2360 
2361     // Element #1: string type for subtag
2362     ASSERT_EQ(EVENT_TYPE_STRING, eventData[0]);
2363     eventData++;
2364 
2365     ASSERT_EQ(strlen(SUBTAG), get4LE(eventData));
2366     eventData += 4;
2367 
2368     if (memcmp(SUBTAG, eventData, strlen(SUBTAG))) {
2369       continue;
2370     }
2371     ++count;
2372   }
2373 
2374   android_logger_list_close(logger_list);
2375 }
2376 #endif
2377 
TEST(liblog,android_errorWriteLog__android_logger_list_read__success)2378 TEST(liblog, android_errorWriteLog__android_logger_list_read__success) {
2379 #ifdef TEST_PREFIX
2380   int count;
2381   android_errorWriteLog_helper(UNIQUE_TAG(5), "test-subtag", count);
2382   EXPECT_EQ(SUPPORTS_END_TO_END, count);
2383 #else
2384   GTEST_LOG_(INFO) << "This test does nothing.\n";
2385 #endif
2386 }
2387 
TEST(liblog,android_errorWriteLog__android_logger_list_read__null_subtag)2388 TEST(liblog, android_errorWriteLog__android_logger_list_read__null_subtag) {
2389 #ifdef TEST_PREFIX
2390   int count;
2391   android_errorWriteLog_helper(UNIQUE_TAG(6), NULL, count);
2392   EXPECT_EQ(0, count);
2393 #else
2394   GTEST_LOG_(INFO) << "This test does nothing.\n";
2395 #endif
2396 }
2397 
2398 // Do not retest logger list handling
2399 #ifdef TEST_PREFIX
is_real_element(int type)2400 static int is_real_element(int type) {
2401   return ((type == EVENT_TYPE_INT) || (type == EVENT_TYPE_LONG) ||
2402           (type == EVENT_TYPE_STRING) || (type == EVENT_TYPE_FLOAT));
2403 }
2404 
android_log_buffer_to_string(const char * msg,size_t len,char * strOut,size_t strOutLen)2405 static int android_log_buffer_to_string(const char* msg, size_t len,
2406                                         char* strOut, size_t strOutLen) {
2407   android_log_context context = create_android_log_parser(msg, len);
2408   android_log_list_element elem;
2409   bool overflow = false;
2410   /* Reserve 1 byte for null terminator. */
2411   size_t origStrOutLen = strOutLen--;
2412 
2413   if (!context) {
2414     return -EBADF;
2415   }
2416 
2417   memset(&elem, 0, sizeof(elem));
2418 
2419   size_t outCount;
2420 
2421   do {
2422     elem = android_log_read_next(context);
2423     switch ((int)elem.type) {
2424       case EVENT_TYPE_LIST:
2425         if (strOutLen == 0) {
2426           overflow = true;
2427         } else {
2428           *strOut++ = '[';
2429           strOutLen--;
2430         }
2431         break;
2432 
2433       case EVENT_TYPE_LIST_STOP:
2434         if (strOutLen == 0) {
2435           overflow = true;
2436         } else {
2437           *strOut++ = ']';
2438           strOutLen--;
2439         }
2440         break;
2441 
2442       case EVENT_TYPE_INT:
2443         /*
2444          * snprintf also requires room for the null terminator, which
2445          * we don't care about  but we have allocated enough room for
2446          * that
2447          */
2448         outCount = snprintf(strOut, strOutLen + 1, "%" PRId32, elem.data.int32);
2449         if (outCount <= strOutLen) {
2450           strOut += outCount;
2451           strOutLen -= outCount;
2452         } else {
2453           overflow = true;
2454         }
2455         break;
2456 
2457       case EVENT_TYPE_LONG:
2458         /*
2459          * snprintf also requires room for the null terminator, which
2460          * we don't care about but we have allocated enough room for
2461          * that
2462          */
2463         outCount = snprintf(strOut, strOutLen + 1, "%" PRId64, elem.data.int64);
2464         if (outCount <= strOutLen) {
2465           strOut += outCount;
2466           strOutLen -= outCount;
2467         } else {
2468           overflow = true;
2469         }
2470         break;
2471 
2472       case EVENT_TYPE_FLOAT:
2473         /*
2474          * snprintf also requires room for the null terminator, which
2475          * we don't care about but we have allocated enough room for
2476          * that
2477          */
2478         outCount = snprintf(strOut, strOutLen + 1, "%f", elem.data.float32);
2479         if (outCount <= strOutLen) {
2480           strOut += outCount;
2481           strOutLen -= outCount;
2482         } else {
2483           overflow = true;
2484         }
2485         break;
2486 
2487       default:
2488         elem.complete = true;
2489         break;
2490 
2491       case EVENT_TYPE_UNKNOWN:
2492 #if 0  // Ideal purity in the test, we want to complain about UNKNOWN showing up
2493             if (elem.complete) {
2494                 break;
2495             }
2496 #endif
2497         elem.data.string = const_cast<char*>("<unknown>");
2498         elem.len = strlen(elem.data.string);
2499         FALLTHROUGH_INTENDED;
2500       case EVENT_TYPE_STRING:
2501         if (elem.len <= strOutLen) {
2502           memcpy(strOut, elem.data.string, elem.len);
2503           strOut += elem.len;
2504           strOutLen -= elem.len;
2505         } else if (strOutLen > 0) {
2506           /* copy what we can */
2507           memcpy(strOut, elem.data.string, strOutLen);
2508           strOut += strOutLen;
2509           strOutLen = 0;
2510           overflow = true;
2511         }
2512         break;
2513     }
2514 
2515     if (elem.complete) {
2516       break;
2517     }
2518     /* Determine whether to put a comma or not. */
2519     if (!overflow &&
2520         (is_real_element(elem.type) || (elem.type == EVENT_TYPE_LIST_STOP))) {
2521       android_log_list_element next = android_log_peek_next(context);
2522       if (!next.complete &&
2523           (is_real_element(next.type) || (next.type == EVENT_TYPE_LIST))) {
2524         if (strOutLen == 0) {
2525           overflow = true;
2526         } else {
2527           *strOut++ = ',';
2528           strOutLen--;
2529         }
2530       }
2531     }
2532   } while ((elem.type != EVENT_TYPE_UNKNOWN) && !overflow && !elem.complete);
2533 
2534   android_log_destroy(&context);
2535 
2536   if (overflow) {
2537     if (strOutLen < origStrOutLen) {
2538       /* leave an indicator */
2539       *(strOut - 1) = '!';
2540     } else {
2541       /* nothing was written at all */
2542       *strOut++ = '!';
2543     }
2544   }
2545   *strOut++ = '\0';
2546 
2547   if ((elem.type == EVENT_TYPE_UNKNOWN) && !elem.complete) {
2548     fprintf(stderr, "Binary log entry conversion failed\n");
2549     return -EINVAL;
2550   }
2551 
2552   return 0;
2553 }
2554 #endif  // TEST_PREFIX
2555 
2556 #ifdef TEST_PREFIX
event_test_int32(uint32_t tag,size_t & expected_len)2557 static const char* event_test_int32(uint32_t tag, size_t& expected_len) {
2558   android_log_context ctx;
2559 
2560   EXPECT_TRUE(NULL != (ctx = create_android_logger(tag)));
2561   if (!ctx) {
2562     return NULL;
2563   }
2564   EXPECT_LE(0, android_log_write_int32(ctx, 0x40302010));
2565   EXPECT_LE(0, android_log_write_list(ctx, LOG_ID_EVENTS));
2566   EXPECT_LE(0, android_log_destroy(&ctx));
2567   EXPECT_TRUE(NULL == ctx);
2568 
2569   expected_len = sizeof(uint32_t) + sizeof(uint8_t) + sizeof(uint32_t);
2570 
2571   return "1076895760";
2572 }
2573 
event_test_int64(uint32_t tag,size_t & expected_len)2574 static const char* event_test_int64(uint32_t tag, size_t& expected_len) {
2575   android_log_context ctx;
2576 
2577   EXPECT_TRUE(NULL != (ctx = create_android_logger(tag)));
2578   if (!ctx) {
2579     return NULL;
2580   }
2581   EXPECT_LE(0, android_log_write_int64(ctx, 0x8070605040302010));
2582   EXPECT_LE(0, android_log_write_list(ctx, LOG_ID_EVENTS));
2583   EXPECT_LE(0, android_log_destroy(&ctx));
2584   EXPECT_TRUE(NULL == ctx);
2585 
2586   expected_len = sizeof(uint32_t) + sizeof(uint8_t) + sizeof(uint64_t);
2587 
2588   return "-9191740941672636400";
2589 }
2590 
event_test_list_int64(uint32_t tag,size_t & expected_len)2591 static const char* event_test_list_int64(uint32_t tag, size_t& expected_len) {
2592   android_log_context ctx;
2593 
2594   EXPECT_TRUE(NULL != (ctx = create_android_logger(tag)));
2595   if (!ctx) {
2596     return NULL;
2597   }
2598   EXPECT_LE(0, android_log_write_list_begin(ctx));
2599   EXPECT_LE(0, android_log_write_int64(ctx, 0x8070605040302010));
2600   EXPECT_LE(0, android_log_write_list_end(ctx));
2601   EXPECT_LE(0, android_log_write_list(ctx, LOG_ID_EVENTS));
2602   EXPECT_LE(0, android_log_destroy(&ctx));
2603   EXPECT_TRUE(NULL == ctx);
2604 
2605   expected_len = sizeof(uint32_t) + sizeof(uint8_t) + sizeof(uint8_t) +
2606                  sizeof(uint8_t) + sizeof(uint64_t);
2607 
2608   return "[-9191740941672636400]";
2609 }
2610 
event_test_simple_automagic_list(uint32_t tag,size_t & expected_len)2611 static const char* event_test_simple_automagic_list(uint32_t tag,
2612                                                     size_t& expected_len) {
2613   android_log_context ctx;
2614 
2615   EXPECT_TRUE(NULL != (ctx = create_android_logger(tag)));
2616   if (!ctx) {
2617     return NULL;
2618   }
2619   // The convenience API where we allow a simple list to be
2620   // created without explicit begin or end calls.
2621   EXPECT_LE(0, android_log_write_int32(ctx, 0x40302010));
2622   EXPECT_LE(0, android_log_write_int64(ctx, 0x8070605040302010));
2623   EXPECT_LE(0, android_log_write_list(ctx, LOG_ID_EVENTS));
2624   EXPECT_LE(0, android_log_destroy(&ctx));
2625   EXPECT_TRUE(NULL == ctx);
2626 
2627   expected_len = sizeof(uint32_t) + sizeof(uint8_t) + sizeof(uint8_t) +
2628                  sizeof(uint8_t) + sizeof(uint32_t) + sizeof(uint8_t) +
2629                  sizeof(uint64_t);
2630 
2631   return "[1076895760,-9191740941672636400]";
2632 }
2633 
event_test_list_empty(uint32_t tag,size_t & expected_len)2634 static const char* event_test_list_empty(uint32_t tag, size_t& expected_len) {
2635   android_log_context ctx;
2636 
2637   EXPECT_TRUE(NULL != (ctx = create_android_logger(tag)));
2638   if (!ctx) {
2639     return NULL;
2640   }
2641   EXPECT_LE(0, android_log_write_list_begin(ctx));
2642   EXPECT_LE(0, android_log_write_list_end(ctx));
2643   EXPECT_LE(0, android_log_write_list(ctx, LOG_ID_EVENTS));
2644   EXPECT_LE(0, android_log_destroy(&ctx));
2645   EXPECT_TRUE(NULL == ctx);
2646 
2647   expected_len = sizeof(uint32_t) + sizeof(uint8_t) + sizeof(uint8_t);
2648 
2649   return "[]";
2650 }
2651 
event_test_complex_nested_list(uint32_t tag,size_t & expected_len)2652 static const char* event_test_complex_nested_list(uint32_t tag,
2653                                                   size_t& expected_len) {
2654   android_log_context ctx;
2655 
2656   EXPECT_TRUE(NULL != (ctx = create_android_logger(tag)));
2657   if (!ctx) {
2658     return NULL;
2659   }
2660 
2661   EXPECT_LE(0, android_log_write_list_begin(ctx));  // [
2662   EXPECT_LE(0, android_log_write_int32(ctx, 0x01020304));
2663   EXPECT_LE(0, android_log_write_int64(ctx, 0x0102030405060708));
2664   EXPECT_LE(0, android_log_write_string8(ctx, "Hello World"));
2665   EXPECT_LE(0, android_log_write_list_begin(ctx));  // [
2666   EXPECT_LE(0, android_log_write_int32(ctx, 1));
2667   EXPECT_LE(0, android_log_write_int32(ctx, 2));
2668   EXPECT_LE(0, android_log_write_int32(ctx, 3));
2669   EXPECT_LE(0, android_log_write_int32(ctx, 4));
2670   EXPECT_LE(0, android_log_write_list_end(ctx));  // ]
2671   EXPECT_LE(0, android_log_write_float32(ctx, 1.0102030405060708));
2672   EXPECT_LE(0, android_log_write_list_end(ctx));  // ]
2673 
2674   //
2675   // This one checks for the automagic list creation because a list
2676   // begin and end was missing for it! This is actually an <oops> corner
2677   // case, and not the behavior we morally support. The automagic API is to
2678   // allow for a simple case of a series of objects in a single list. e.g.
2679   //   int32,int32,int32,string -> [int32,int32,int32,string]
2680   //
2681   EXPECT_LE(0, android_log_write_string8(ctx, "dlroW olleH"));
2682 
2683   EXPECT_LE(0, android_log_write_list(ctx, LOG_ID_EVENTS));
2684   EXPECT_LE(0, android_log_destroy(&ctx));
2685   EXPECT_TRUE(NULL == ctx);
2686 
2687   expected_len = sizeof(uint32_t) + sizeof(uint8_t) + sizeof(uint8_t) +
2688                  sizeof(uint8_t) + sizeof(uint8_t) + sizeof(uint8_t) +
2689                  sizeof(uint32_t) + sizeof(uint8_t) + sizeof(uint64_t) +
2690                  sizeof(uint8_t) + sizeof(uint32_t) + sizeof("Hello World") -
2691                  1 + sizeof(uint8_t) + sizeof(uint8_t) +
2692                  4 * (sizeof(uint8_t) + sizeof(uint32_t)) + sizeof(uint8_t) +
2693                  sizeof(uint32_t) + sizeof(uint8_t) + sizeof(uint32_t) +
2694                  sizeof("dlroW olleH") - 1;
2695 
2696   return "[[16909060,72623859790382856,Hello World,[1,2,3,4],1.010203],dlroW "
2697          "olleH]";
2698 }
2699 
event_test_7_level_prefix(uint32_t tag,size_t & expected_len)2700 static const char* event_test_7_level_prefix(uint32_t tag,
2701                                              size_t& expected_len) {
2702   android_log_context ctx;
2703 
2704   EXPECT_TRUE(NULL != (ctx = create_android_logger(tag)));
2705   if (!ctx) {
2706     return NULL;
2707   }
2708   EXPECT_LE(0, android_log_write_list_begin(ctx));
2709   EXPECT_LE(0, android_log_write_list_begin(ctx));
2710   EXPECT_LE(0, android_log_write_list_begin(ctx));
2711   EXPECT_LE(0, android_log_write_list_begin(ctx));
2712   EXPECT_LE(0, android_log_write_list_begin(ctx));
2713   EXPECT_LE(0, android_log_write_list_begin(ctx));
2714   EXPECT_LE(0, android_log_write_list_begin(ctx));
2715   EXPECT_LE(0, android_log_write_int32(ctx, 1));
2716   EXPECT_LE(0, android_log_write_list_end(ctx));
2717   EXPECT_LE(0, android_log_write_int32(ctx, 2));
2718   EXPECT_LE(0, android_log_write_list_end(ctx));
2719   EXPECT_LE(0, android_log_write_int32(ctx, 3));
2720   EXPECT_LE(0, android_log_write_list_end(ctx));
2721   EXPECT_LE(0, android_log_write_int32(ctx, 4));
2722   EXPECT_LE(0, android_log_write_list_end(ctx));
2723   EXPECT_LE(0, android_log_write_int32(ctx, 5));
2724   EXPECT_LE(0, android_log_write_list_end(ctx));
2725   EXPECT_LE(0, android_log_write_int32(ctx, 6));
2726   EXPECT_LE(0, android_log_write_list_end(ctx));
2727   EXPECT_LE(0, android_log_write_int32(ctx, 7));
2728   EXPECT_LE(0, android_log_write_list_end(ctx));
2729   EXPECT_LE(0, android_log_write_list(ctx, LOG_ID_EVENTS));
2730   EXPECT_LE(0, android_log_destroy(&ctx));
2731   EXPECT_TRUE(NULL == ctx);
2732 
2733   expected_len = sizeof(uint32_t) + 7 * (sizeof(uint8_t) + sizeof(uint8_t) +
2734                                          sizeof(uint8_t) + sizeof(uint32_t));
2735 
2736   return "[[[[[[[1],2],3],4],5],6],7]";
2737 }
2738 
event_test_7_level_suffix(uint32_t tag,size_t & expected_len)2739 static const char* event_test_7_level_suffix(uint32_t tag,
2740                                              size_t& expected_len) {
2741   android_log_context ctx;
2742 
2743   EXPECT_TRUE(NULL != (ctx = create_android_logger(tag)));
2744   if (!ctx) {
2745     return NULL;
2746   }
2747   EXPECT_LE(0, android_log_write_list_begin(ctx));
2748   EXPECT_LE(0, android_log_write_int32(ctx, 1));
2749   EXPECT_LE(0, android_log_write_list_begin(ctx));
2750   EXPECT_LE(0, android_log_write_int32(ctx, 2));
2751   EXPECT_LE(0, android_log_write_list_begin(ctx));
2752   EXPECT_LE(0, android_log_write_int32(ctx, 3));
2753   EXPECT_LE(0, android_log_write_list_begin(ctx));
2754   EXPECT_LE(0, android_log_write_int32(ctx, 4));
2755   EXPECT_LE(0, android_log_write_list_begin(ctx));
2756   EXPECT_LE(0, android_log_write_int32(ctx, 5));
2757   EXPECT_LE(0, android_log_write_list_begin(ctx));
2758   EXPECT_LE(0, android_log_write_int32(ctx, 6));
2759   EXPECT_LE(0, android_log_write_list_end(ctx));
2760   EXPECT_LE(0, android_log_write_list_end(ctx));
2761   EXPECT_LE(0, android_log_write_list_end(ctx));
2762   EXPECT_LE(0, android_log_write_list_end(ctx));
2763   EXPECT_LE(0, android_log_write_list_end(ctx));
2764   EXPECT_LE(0, android_log_write_list_end(ctx));
2765   EXPECT_LE(0, android_log_write_list(ctx, LOG_ID_EVENTS));
2766   EXPECT_LE(0, android_log_destroy(&ctx));
2767   EXPECT_TRUE(NULL == ctx);
2768 
2769   expected_len = sizeof(uint32_t) + 6 * (sizeof(uint8_t) + sizeof(uint8_t) +
2770                                          sizeof(uint8_t) + sizeof(uint32_t));
2771 
2772   return "[1,[2,[3,[4,[5,[6]]]]]]";
2773 }
2774 
event_test_android_log_error_write(uint32_t tag,size_t & expected_len)2775 static const char* event_test_android_log_error_write(uint32_t tag,
2776                                                       size_t& expected_len) {
2777   EXPECT_LE(
2778       0, __android_log_error_write(tag, "Hello World", 42, "dlroW olleH", 11));
2779 
2780   expected_len = sizeof(uint32_t) + sizeof(uint8_t) + sizeof(uint8_t) +
2781                  sizeof(uint8_t) + sizeof(uint32_t) + sizeof("Hello World") -
2782                  1 + sizeof(uint8_t) + sizeof(uint32_t) + sizeof(uint8_t) +
2783                  sizeof(uint32_t) + sizeof("dlroW olleH") - 1;
2784 
2785   return "[Hello World,42,dlroW olleH]";
2786 }
2787 
event_test_android_log_error_write_null(uint32_t tag,size_t & expected_len)2788 static const char* event_test_android_log_error_write_null(uint32_t tag,
2789                                                            size_t& expected_len) {
2790   EXPECT_LE(0, __android_log_error_write(tag, "Hello World", 42, NULL, 0));
2791 
2792   expected_len = sizeof(uint32_t) + sizeof(uint8_t) + sizeof(uint8_t) +
2793                  sizeof(uint8_t) + sizeof(uint32_t) + sizeof("Hello World") -
2794                  1 + sizeof(uint8_t) + sizeof(uint32_t) + sizeof(uint8_t) +
2795                  sizeof(uint32_t) + sizeof("") - 1;
2796 
2797   return "[Hello World,42,]";
2798 }
2799 
2800 // make sure all user buffers are flushed
print_barrier()2801 static void print_barrier() {
2802   std::cout.flush();
2803   fflush(stdout);
2804   std::cerr.flush();
2805   fflush(stderr);  // everything else is paranoia ...
2806 }
2807 
create_android_logger(const char * (* fn)(uint32_t tag,size_t & expected_len))2808 static void create_android_logger(const char* (*fn)(uint32_t tag,
2809                                                     size_t& expected_len)) {
2810   TEST_PREFIX
2811   struct logger_list* logger_list;
2812 
2813   pid_t pid = getpid();
2814 
2815   ASSERT_TRUE(NULL !=
2816               (logger_list = android_logger_list_open(
2817                    LOG_ID_EVENTS, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK,
2818                    1000, pid)));
2819 
2820 #ifdef __ANDROID__
2821   log_time ts(android_log_clockid());
2822 #else
2823   log_time ts(CLOCK_REALTIME);
2824 #endif
2825 
2826   size_t expected_len;
2827   const char* expected_string = (*fn)(1005, expected_len);
2828 
2829   if (!expected_string) {
2830     android_logger_list_close(logger_list);
2831     return;
2832   }
2833 
2834   usleep(1000000);
2835 
2836   int count = 0;
2837 
2838   for (;;) {
2839     log_msg log_msg;
2840     if (android_logger_list_read(logger_list, &log_msg) <= 0) {
2841       break;
2842     }
2843 
2844     ASSERT_EQ(log_msg.entry.pid, pid);
2845 
2846     if ((log_msg.entry.sec < (ts.tv_sec - 1)) ||
2847         ((ts.tv_sec + 1) < log_msg.entry.sec) ||
2848         ((size_t)log_msg.entry.len != expected_len) ||
2849         (log_msg.id() != LOG_ID_EVENTS)) {
2850       continue;
2851     }
2852 
2853     char* eventData = log_msg.msg();
2854 
2855     ++count;
2856 
2857     AndroidLogFormat* logformat = android_log_format_new();
2858     EXPECT_TRUE(NULL != logformat);
2859     AndroidLogEntry entry;
2860     char msgBuf[1024];
2861     int processBinaryLogBuffer = android_log_processBinaryLogBuffer(
2862         &log_msg.entry_v1, &entry, NULL, msgBuf, sizeof(msgBuf));
2863     EXPECT_EQ(0, processBinaryLogBuffer);
2864     if (processBinaryLogBuffer == 0) {
2865       int line_overhead = 20;
2866       if (pid > 99999) ++line_overhead;
2867       if (pid > 999999) ++line_overhead;
2868       print_barrier();
2869       int printLogLine =
2870           android_log_printLogLine(logformat, fileno(stderr), &entry);
2871       print_barrier();
2872       EXPECT_EQ(line_overhead + (int)strlen(expected_string), printLogLine);
2873     }
2874     android_log_format_free(logformat);
2875 
2876     // test buffer reading API
2877     int buffer_to_string = -1;
2878     if (eventData) {
2879       snprintf(msgBuf, sizeof(msgBuf), "I/[%" PRIu32 "]", get4LE(eventData));
2880       print_barrier();
2881       fprintf(stderr, "%-10s(%5u): ", msgBuf, pid);
2882       memset(msgBuf, 0, sizeof(msgBuf));
2883       buffer_to_string = android_log_buffer_to_string(
2884           eventData + sizeof(uint32_t), log_msg.entry.len - sizeof(uint32_t),
2885           msgBuf, sizeof(msgBuf));
2886       fprintf(stderr, "%s\n", msgBuf);
2887       print_barrier();
2888     }
2889     EXPECT_EQ(0, buffer_to_string);
2890     EXPECT_EQ(strlen(expected_string), strlen(msgBuf));
2891     EXPECT_EQ(0, strcmp(expected_string, msgBuf));
2892   }
2893 
2894   EXPECT_EQ(SUPPORTS_END_TO_END, count);
2895 
2896   android_logger_list_close(logger_list);
2897 }
2898 #endif
2899 
TEST(liblog,create_android_logger_int32)2900 TEST(liblog, create_android_logger_int32) {
2901 #ifdef TEST_PREFIX
2902   create_android_logger(event_test_int32);
2903 #else
2904   GTEST_LOG_(INFO) << "This test does nothing.\n";
2905 #endif
2906 }
2907 
TEST(liblog,create_android_logger_int64)2908 TEST(liblog, create_android_logger_int64) {
2909 #ifdef TEST_PREFIX
2910   create_android_logger(event_test_int64);
2911 #else
2912   GTEST_LOG_(INFO) << "This test does nothing.\n";
2913 #endif
2914 }
2915 
TEST(liblog,create_android_logger_list_int64)2916 TEST(liblog, create_android_logger_list_int64) {
2917 #ifdef TEST_PREFIX
2918   create_android_logger(event_test_list_int64);
2919 #else
2920   GTEST_LOG_(INFO) << "This test does nothing.\n";
2921 #endif
2922 }
2923 
TEST(liblog,create_android_logger_simple_automagic_list)2924 TEST(liblog, create_android_logger_simple_automagic_list) {
2925 #ifdef TEST_PREFIX
2926   create_android_logger(event_test_simple_automagic_list);
2927 #else
2928   GTEST_LOG_(INFO) << "This test does nothing.\n";
2929 #endif
2930 }
2931 
TEST(liblog,create_android_logger_list_empty)2932 TEST(liblog, create_android_logger_list_empty) {
2933 #ifdef TEST_PREFIX
2934   create_android_logger(event_test_list_empty);
2935 #else
2936   GTEST_LOG_(INFO) << "This test does nothing.\n";
2937 #endif
2938 }
2939 
TEST(liblog,create_android_logger_complex_nested_list)2940 TEST(liblog, create_android_logger_complex_nested_list) {
2941 #ifdef TEST_PREFIX
2942   create_android_logger(event_test_complex_nested_list);
2943 #else
2944   GTEST_LOG_(INFO) << "This test does nothing.\n";
2945 #endif
2946 }
2947 
TEST(liblog,create_android_logger_7_level_prefix)2948 TEST(liblog, create_android_logger_7_level_prefix) {
2949 #ifdef TEST_PREFIX
2950   create_android_logger(event_test_7_level_prefix);
2951 #else
2952   GTEST_LOG_(INFO) << "This test does nothing.\n";
2953 #endif
2954 }
2955 
TEST(liblog,create_android_logger_7_level_suffix)2956 TEST(liblog, create_android_logger_7_level_suffix) {
2957 #ifdef TEST_PREFIX
2958   create_android_logger(event_test_7_level_suffix);
2959 #else
2960   GTEST_LOG_(INFO) << "This test does nothing.\n";
2961 #endif
2962 }
2963 
TEST(liblog,create_android_logger_android_log_error_write)2964 TEST(liblog, create_android_logger_android_log_error_write) {
2965 #ifdef TEST_PREFIX
2966   create_android_logger(event_test_android_log_error_write);
2967 #else
2968   GTEST_LOG_(INFO) << "This test does nothing.\n";
2969 #endif
2970 }
2971 
TEST(liblog,create_android_logger_android_log_error_write_null)2972 TEST(liblog, create_android_logger_android_log_error_write_null) {
2973 #ifdef TEST_PREFIX
2974   create_android_logger(event_test_android_log_error_write_null);
2975 #else
2976   GTEST_LOG_(INFO) << "This test does nothing.\n";
2977 #endif
2978 }
2979 
2980 #ifdef USING_LOGGER_DEFAULT  // Do not retest logger list handling
TEST(liblog,create_android_logger_overflow)2981 TEST(liblog, create_android_logger_overflow) {
2982   android_log_context ctx;
2983 
2984   EXPECT_TRUE(NULL != (ctx = create_android_logger(1005)));
2985   if (ctx) {
2986     for (size_t i = 0; i < ANDROID_MAX_LIST_NEST_DEPTH; ++i) {
2987       EXPECT_LE(0, android_log_write_list_begin(ctx));
2988     }
2989     EXPECT_GT(0, android_log_write_list_begin(ctx));
2990     /* One more for good measure, must be permanently unhappy */
2991     EXPECT_GT(0, android_log_write_list_begin(ctx));
2992     EXPECT_LE(0, android_log_destroy(&ctx));
2993     EXPECT_TRUE(NULL == ctx);
2994   }
2995 
2996   ASSERT_TRUE(NULL != (ctx = create_android_logger(1005)));
2997   for (size_t i = 0; i < ANDROID_MAX_LIST_NEST_DEPTH; ++i) {
2998     EXPECT_LE(0, android_log_write_list_begin(ctx));
2999     EXPECT_LE(0, android_log_write_int32(ctx, i));
3000   }
3001   EXPECT_GT(0, android_log_write_list_begin(ctx));
3002   /* One more for good measure, must be permanently unhappy */
3003   EXPECT_GT(0, android_log_write_list_begin(ctx));
3004   EXPECT_LE(0, android_log_destroy(&ctx));
3005   ASSERT_TRUE(NULL == ctx);
3006 }
3007 
TEST(liblog,android_log_write_list_buffer)3008 TEST(liblog, android_log_write_list_buffer) {
3009   __android_log_event_list ctx(1005);
3010   ctx << 1005 << "tag_def"
3011       << "(tag|1),(name|3),(format|3)";
3012   std::string buffer(ctx);
3013   ctx.close();
3014 
3015   char msgBuf[1024];
3016   memset(msgBuf, 0, sizeof(msgBuf));
3017   EXPECT_EQ(android_log_buffer_to_string(buffer.data(), buffer.length(), msgBuf,
3018                                          sizeof(msgBuf)),
3019             0);
3020   EXPECT_STREQ(msgBuf, "[1005,tag_def,(tag|1),(name|3),(format|3)]");
3021 }
3022 #endif  // USING_LOGGER_DEFAULT
3023 
3024 #ifdef USING_LOGGER_DEFAULT  // Do not retest pmsg functionality
3025 #ifdef __ANDROID__
3026 #ifndef NO_PSTORE
3027 static const char __pmsg_file[] =
3028     "/data/william-shakespeare/MuchAdoAboutNothing.txt";
3029 #endif /* NO_PSTORE */
3030 #endif
3031 
TEST(liblog,__android_log_pmsg_file_write)3032 TEST(liblog, __android_log_pmsg_file_write) {
3033 #ifdef __ANDROID__
3034 #ifndef NO_PSTORE
3035   __android_log_close();
3036   if (getuid() == AID_ROOT) {
3037     tested__android_log_close = true;
3038     bool pmsgActiveAfter__android_log_close = isPmsgActive();
3039     bool logdwActiveAfter__android_log_close = isLogdwActive();
3040     EXPECT_FALSE(pmsgActiveAfter__android_log_close);
3041     EXPECT_FALSE(logdwActiveAfter__android_log_close);
3042   } else if (!tested__android_log_close) {
3043     fprintf(stderr, "WARNING: can not test __android_log_close()\n");
3044   }
3045   int return__android_log_pmsg_file_write = __android_log_pmsg_file_write(
3046       LOG_ID_CRASH, ANDROID_LOG_VERBOSE, __pmsg_file, max_payload_buf,
3047       sizeof(max_payload_buf));
3048   EXPECT_LT(0, return__android_log_pmsg_file_write);
3049   if (return__android_log_pmsg_file_write == -ENOMEM) {
3050     fprintf(stderr,
3051             "Kernel does not have space allocated to pmsg pstore driver "
3052             "configured\n");
3053   } else if (!return__android_log_pmsg_file_write) {
3054     fprintf(stderr,
3055             "Reboot, ensure file %s matches\n"
3056             "with liblog.__android_log_msg_file_read test\n",
3057             __pmsg_file);
3058   }
3059   bool pmsgActiveAfter__android_pmsg_file_write;
3060   bool logdwActiveAfter__android_pmsg_file_write;
3061   if (getuid() == AID_ROOT) {
3062     pmsgActiveAfter__android_pmsg_file_write = isPmsgActive();
3063     logdwActiveAfter__android_pmsg_file_write = isLogdwActive();
3064     EXPECT_FALSE(pmsgActiveAfter__android_pmsg_file_write);
3065     EXPECT_FALSE(logdwActiveAfter__android_pmsg_file_write);
3066   }
3067   EXPECT_LT(
3068       0, __android_log_buf_print(LOG_ID_MAIN, ANDROID_LOG_INFO,
3069                                  "TEST__android_log_pmsg_file_write", "main"));
3070   if (getuid() == AID_ROOT) {
3071     bool pmsgActiveAfter__android_log_buf_print = isPmsgActive();
3072     bool logdwActiveAfter__android_log_buf_print = isLogdwActive();
3073     EXPECT_TRUE(pmsgActiveAfter__android_log_buf_print);
3074     EXPECT_TRUE(logdwActiveAfter__android_log_buf_print);
3075   }
3076   EXPECT_LT(0, __android_log_pmsg_file_write(LOG_ID_CRASH, ANDROID_LOG_VERBOSE,
3077                                              __pmsg_file, max_payload_buf,
3078                                              sizeof(max_payload_buf)));
3079   if (getuid() == AID_ROOT) {
3080     pmsgActiveAfter__android_pmsg_file_write = isPmsgActive();
3081     logdwActiveAfter__android_pmsg_file_write = isLogdwActive();
3082     EXPECT_TRUE(pmsgActiveAfter__android_pmsg_file_write);
3083     EXPECT_TRUE(logdwActiveAfter__android_pmsg_file_write);
3084   }
3085 #else  /* NO_PSTORE */
3086   GTEST_LOG_(INFO) << "This test does nothing because of NO_PSTORE.\n";
3087 #endif /* NO_PSTORE */
3088 #else
3089   GTEST_LOG_(INFO) << "This test does nothing.\n";
3090 #endif
3091 }
3092 
3093 #ifdef __ANDROID__
3094 #ifndef NO_PSTORE
__pmsg_fn(log_id_t logId,char prio,const char * filename,const char * buf,size_t len,void * arg)3095 static ssize_t __pmsg_fn(log_id_t logId, char prio, const char* filename,
3096                          const char* buf, size_t len, void* arg) {
3097   EXPECT_TRUE(NULL == arg);
3098   EXPECT_EQ(LOG_ID_CRASH, logId);
3099   EXPECT_EQ(ANDROID_LOG_VERBOSE, prio);
3100   EXPECT_FALSE(NULL == strstr(__pmsg_file, filename));
3101   EXPECT_EQ(len, sizeof(max_payload_buf));
3102   EXPECT_EQ(0, strcmp(max_payload_buf, buf));
3103 
3104   ++signaled;
3105   if ((len != sizeof(max_payload_buf)) || strcmp(max_payload_buf, buf)) {
3106     fprintf(stderr, "comparison fails on content \"%s\"\n", buf);
3107   }
3108   return arg || (LOG_ID_CRASH != logId) || (ANDROID_LOG_VERBOSE != prio) ||
3109                  !strstr(__pmsg_file, filename) ||
3110                  (len != sizeof(max_payload_buf)) ||
3111                  !!strcmp(max_payload_buf, buf)
3112              ? -ENOEXEC
3113              : 1;
3114 }
3115 #endif /* NO_PSTORE */
3116 #endif
3117 
TEST(liblog,__android_log_pmsg_file_read)3118 TEST(liblog, __android_log_pmsg_file_read) {
3119 #ifdef __ANDROID__
3120 #ifndef NO_PSTORE
3121   signaled = 0;
3122 
3123   __android_log_close();
3124   if (getuid() == AID_ROOT) {
3125     tested__android_log_close = true;
3126     bool pmsgActiveAfter__android_log_close = isPmsgActive();
3127     bool logdwActiveAfter__android_log_close = isLogdwActive();
3128     EXPECT_FALSE(pmsgActiveAfter__android_log_close);
3129     EXPECT_FALSE(logdwActiveAfter__android_log_close);
3130   } else if (!tested__android_log_close) {
3131     fprintf(stderr, "WARNING: can not test __android_log_close()\n");
3132   }
3133 
3134   ssize_t ret = __android_log_pmsg_file_read(LOG_ID_CRASH, ANDROID_LOG_VERBOSE,
3135                                              __pmsg_file, __pmsg_fn, NULL);
3136 
3137   if (getuid() == AID_ROOT) {
3138     bool pmsgActiveAfter__android_log_pmsg_file_read = isPmsgActive();
3139     bool logdwActiveAfter__android_log_pmsg_file_read = isLogdwActive();
3140     EXPECT_FALSE(pmsgActiveAfter__android_log_pmsg_file_read);
3141     EXPECT_FALSE(logdwActiveAfter__android_log_pmsg_file_read);
3142   }
3143 
3144   if (ret == -ENOENT) {
3145     fprintf(stderr,
3146             "No pre-boot results of liblog.__android_log_mesg_file_write to "
3147             "compare with,\n"
3148             "false positive test result.\n");
3149     return;
3150   }
3151 
3152   EXPECT_LT(0, ret);
3153   EXPECT_EQ(1U, signaled);
3154 #else  /* NO_PSTORE */
3155   GTEST_LOG_(INFO) << "This test does nothing because of NO_PSTORE.\n";
3156 #endif /* NO_PSTORE */
3157 #else
3158   GTEST_LOG_(INFO) << "This test does nothing.\n";
3159 #endif
3160 }
3161 #endif  // USING_LOGGER_DEFAULT
3162 
3163 #ifdef USING_LOGGER_DEFAULT  // Do not retest event mapping functionality
TEST(liblog,android_lookupEventTagNum)3164 TEST(liblog, android_lookupEventTagNum) {
3165 #ifdef __ANDROID__
3166   EventTagMap* map = android_openEventTagMap(NULL);
3167   EXPECT_TRUE(NULL != map);
3168   std::string Name = android::base::StringPrintf("a%d", getpid());
3169   int tag = android_lookupEventTagNum(map, Name.c_str(), "(new|1)",
3170                                       ANDROID_LOG_UNKNOWN);
3171   android_closeEventTagMap(map);
3172   if (tag == -1) system("tail -3 /dev/event-log-tags >&2");
3173   EXPECT_NE(-1, tag);
3174   EXPECT_NE(0, tag);
3175   EXPECT_GT(UINT32_MAX, (unsigned)tag);
3176 #else
3177   GTEST_LOG_(INFO) << "This test does nothing.\n";
3178 #endif
3179 }
3180 #endif  // USING_LOGGER_DEFAULT
3181