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