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