blob: 6aa4fb78608b75fe696433ddac5e1a43fcad67a3 [file] [log] [blame]
Mark Salyzyn819c58a2013-11-22 12:39:43 -08001/*
Mark Salyzyn9dd65102016-02-17 16:08:13 -08002 * Copyright (C) 2013-2016 The Android Open Source Project
Mark Salyzyn819c58a2013-11-22 12:39:43 -08003 *
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 <fcntl.h>
Elliott Hughes5d9fe772014-02-05 17:50:35 -080018#include <inttypes.h>
Mark Salyzyna6f2f812016-03-10 15:25:14 -080019#include <semaphore.h>
Mark Salyzyncef098e2014-01-09 09:02:55 -080020#include <signal.h>
William Luh964428c2015-08-13 10:41:58 -070021#include <string.h>
Mark Salyzyn8fa88962016-01-26 14:32:35 -080022#include <sys/types.h>
23#include <unistd.h>
Mark Salyzync1584562015-03-12 15:46:29 -070024
25#include <cutils/properties.h>
Mark Salyzyn819c58a2013-11-22 12:39:43 -080026#include <gtest/gtest.h>
27#include <log/log.h>
28#include <log/logger.h>
29#include <log/log_read.h>
Mark Salyzyn5045f572014-04-30 08:50:53 -070030#include <log/logprint.h>
Mark Salyzyn8fa88962016-01-26 14:32:35 -080031#include <private/android_filesystem_config.h>
Mark Salyzyn083b0372015-12-04 10:59:45 -080032#include <private/android_logger.h>
Mark Salyzyn819c58a2013-11-22 12:39:43 -080033
Mark Salyzyncef098e2014-01-09 09:02:55 -080034// enhanced version of LOG_FAILURE_RETRY to add support for EAGAIN and
35// non-syscall libs. Since we are only using this in the emergency of
36// a signal to stuff a terminating code into the logs, we will spin rather
37// than try a usleep.
38#define LOG_FAILURE_RETRY(exp) ({ \
39 typeof (exp) _rc; \
40 do { \
41 _rc = (exp); \
42 } while (((_rc == -1) \
43 && ((errno == EINTR) \
44 || (errno == EAGAIN))) \
45 || (_rc == -EINTR) \
46 || (_rc == -EAGAIN)); \
47 _rc; })
48
Mark Salyzyn819c58a2013-11-22 12:39:43 -080049TEST(liblog, __android_log_buf_print) {
Mark Salyzyn8196be32014-03-18 17:10:47 -070050 EXPECT_LT(0, __android_log_buf_print(LOG_ID_RADIO, ANDROID_LOG_INFO,
Mark Salyzyn819c58a2013-11-22 12:39:43 -080051 "TEST__android_log_buf_print",
52 "radio"));
53 usleep(1000);
Mark Salyzyn8196be32014-03-18 17:10:47 -070054 EXPECT_LT(0, __android_log_buf_print(LOG_ID_SYSTEM, ANDROID_LOG_INFO,
Mark Salyzyn819c58a2013-11-22 12:39:43 -080055 "TEST__android_log_buf_print",
56 "system"));
57 usleep(1000);
Mark Salyzyn8196be32014-03-18 17:10:47 -070058 EXPECT_LT(0, __android_log_buf_print(LOG_ID_MAIN, ANDROID_LOG_INFO,
Mark Salyzyn819c58a2013-11-22 12:39:43 -080059 "TEST__android_log_buf_print",
60 "main"));
61 usleep(1000);
62}
63
64TEST(liblog, __android_log_buf_write) {
Mark Salyzyn8196be32014-03-18 17:10:47 -070065 EXPECT_LT(0, __android_log_buf_write(LOG_ID_RADIO, ANDROID_LOG_INFO,
Mark Salyzyn819c58a2013-11-22 12:39:43 -080066 "TEST__android_log_buf_write",
67 "radio"));
68 usleep(1000);
Mark Salyzyn8196be32014-03-18 17:10:47 -070069 EXPECT_LT(0, __android_log_buf_write(LOG_ID_SYSTEM, ANDROID_LOG_INFO,
Mark Salyzyn819c58a2013-11-22 12:39:43 -080070 "TEST__android_log_buf_write",
71 "system"));
72 usleep(1000);
Mark Salyzyn8196be32014-03-18 17:10:47 -070073 EXPECT_LT(0, __android_log_buf_write(LOG_ID_MAIN, ANDROID_LOG_INFO,
Mark Salyzyn819c58a2013-11-22 12:39:43 -080074 "TEST__android_log_buf_write",
75 "main"));
76 usleep(1000);
77}
78
79TEST(liblog, __android_log_btwrite) {
80 int intBuf = 0xDEADBEEF;
Mark Salyzyn8196be32014-03-18 17:10:47 -070081 EXPECT_LT(0, __android_log_btwrite(0,
Mark Salyzyn819c58a2013-11-22 12:39:43 -080082 EVENT_TYPE_INT,
83 &intBuf, sizeof(intBuf)));
84 long long longBuf = 0xDEADBEEFA55A5AA5;
Mark Salyzyn8196be32014-03-18 17:10:47 -070085 EXPECT_LT(0, __android_log_btwrite(0,
Mark Salyzyn819c58a2013-11-22 12:39:43 -080086 EVENT_TYPE_LONG,
87 &longBuf, sizeof(longBuf)));
88 usleep(1000);
89 char Buf[] = "\20\0\0\0DeAdBeEfA55a5aA5";
Mark Salyzyn8196be32014-03-18 17:10:47 -070090 EXPECT_LT(0, __android_log_btwrite(0,
Mark Salyzyn819c58a2013-11-22 12:39:43 -080091 EVENT_TYPE_STRING,
92 Buf, sizeof(Buf) - 1));
93 usleep(1000);
94}
95
96static void* ConcurrentPrintFn(void *arg) {
97 int ret = __android_log_buf_print(LOG_ID_MAIN, ANDROID_LOG_INFO,
Elliott Hughes5d9fe772014-02-05 17:50:35 -080098 "TEST__android_log_print", "Concurrent %" PRIuPTR,
99 reinterpret_cast<uintptr_t>(arg));
Mark Salyzyn819c58a2013-11-22 12:39:43 -0800100 return reinterpret_cast<void*>(ret);
101}
102
103#define NUM_CONCURRENT 64
104#define _concurrent_name(a,n) a##__concurrent##n
105#define concurrent_name(a,n) _concurrent_name(a,n)
106
107TEST(liblog, concurrent_name(__android_log_buf_print, NUM_CONCURRENT)) {
108 pthread_t t[NUM_CONCURRENT];
109 int i;
110 for (i=0; i < NUM_CONCURRENT; i++) {
111 ASSERT_EQ(0, pthread_create(&t[i], NULL,
112 ConcurrentPrintFn,
113 reinterpret_cast<void *>(i)));
114 }
115 int ret = 0;
116 for (i=0; i < NUM_CONCURRENT; i++) {
117 void* result;
118 ASSERT_EQ(0, pthread_join(t[i], &result));
Elliott Hughes5d9fe772014-02-05 17:50:35 -0800119 int this_result = reinterpret_cast<uintptr_t>(result);
120 if ((0 == ret) && (0 != this_result)) {
121 ret = this_result;
Mark Salyzyn819c58a2013-11-22 12:39:43 -0800122 }
123 }
124 ASSERT_LT(0, ret);
125}
126
127TEST(liblog, __android_log_btwrite__android_logger_list_read) {
128 struct logger_list *logger_list;
129
130 pid_t pid = getpid();
131
Mark Salyzyn8196be32014-03-18 17:10:47 -0700132 ASSERT_TRUE(NULL != (logger_list = android_logger_list_open(
Mark Salyzyn2d3f38a2015-01-26 10:46:44 -0800133 LOG_ID_EVENTS, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 1000, pid)));
Mark Salyzyn819c58a2013-11-22 12:39:43 -0800134
135 log_time ts(CLOCK_MONOTONIC);
136
137 ASSERT_LT(0, __android_log_btwrite(0, EVENT_TYPE_LONG, &ts, sizeof(ts)));
138 usleep(1000000);
139
140 int count = 0;
141
142 for (;;) {
143 log_msg log_msg;
144 if (android_logger_list_read(logger_list, &log_msg) <= 0) {
145 break;
146 }
147
148 ASSERT_EQ(log_msg.entry.pid, pid);
149
150 if ((log_msg.entry.len != (4 + 1 + 8))
151 || (log_msg.id() != LOG_ID_EVENTS)) {
152 continue;
153 }
154
155 char *eventData = log_msg.msg();
156
157 if (eventData[4] != EVENT_TYPE_LONG) {
158 continue;
159 }
160
161 log_time tx(eventData + 4 + 1);
162 if (ts == tx) {
163 ++count;
164 }
165 }
166
Mark Salyzyn8196be32014-03-18 17:10:47 -0700167 EXPECT_EQ(1, count);
Mark Salyzyn819c58a2013-11-22 12:39:43 -0800168
169 android_logger_list_close(logger_list);
170}
171
Mark Salyzyn7cc80132016-01-20 13:52:46 -0800172static inline int32_t get4LE(const char* src)
173{
174 return src[0] | (src[1] << 8) | (src[2] << 16) | (src[3] << 24);
175}
176
177TEST(liblog, __android_log_bswrite) {
178 struct logger_list *logger_list;
179
180 pid_t pid = getpid();
181
182 ASSERT_TRUE(NULL != (logger_list = android_logger_list_open(
183 LOG_ID_EVENTS, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 1000, pid)));
184
185 static const char buffer[] = "Hello World";
186 log_time ts(android_log_clockid());
187
188 ASSERT_LT(0, __android_log_bswrite(0, buffer));
189 usleep(1000000);
190
191 int count = 0;
192
193 for (;;) {
194 log_msg log_msg;
195 if (android_logger_list_read(logger_list, &log_msg) <= 0) {
196 break;
197 }
198
199 ASSERT_EQ(log_msg.entry.pid, pid);
200
201 if ((log_msg.entry.sec < (ts.tv_sec - 1))
202 || ((ts.tv_sec + 1) < log_msg.entry.sec)
203 || (log_msg.entry.len != (4 + 1 + 4 + sizeof(buffer) - 1))
204 || (log_msg.id() != LOG_ID_EVENTS)) {
205 continue;
206 }
207
208 char *eventData = log_msg.msg();
209
210 if (eventData[4] != EVENT_TYPE_STRING) {
211 continue;
212 }
213
214 int len = get4LE(eventData + 4 + 1);
215 if (len == (sizeof(buffer) - 1)) {
216 ++count;
217
218 AndroidLogFormat *logformat = android_log_format_new();
219 EXPECT_TRUE(NULL != logformat);
220 AndroidLogEntry entry;
221 char msgBuf[1024];
222 EXPECT_EQ(0, android_log_processBinaryLogBuffer(&log_msg.entry_v1,
223 &entry,
224 NULL,
225 msgBuf,
226 sizeof(msgBuf)));
227 fflush(stderr);
228 EXPECT_EQ(31, android_log_printLogLine(logformat, fileno(stderr), &entry));
229 android_log_format_free(logformat);
230 }
231 }
232
233 EXPECT_EQ(1, count);
234
235 android_logger_list_close(logger_list);
236}
237
238TEST(liblog, __android_log_bswrite__empty_string) {
239 struct logger_list *logger_list;
240
241 pid_t pid = getpid();
242
243 ASSERT_TRUE(NULL != (logger_list = android_logger_list_open(
244 LOG_ID_EVENTS, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 1000, pid)));
245
246 static const char buffer[] = "";
247 log_time ts(android_log_clockid());
248
249 ASSERT_LT(0, __android_log_bswrite(0, buffer));
250 usleep(1000000);
251
252 int count = 0;
253
254 for (;;) {
255 log_msg log_msg;
256 if (android_logger_list_read(logger_list, &log_msg) <= 0) {
257 break;
258 }
259
260 ASSERT_EQ(log_msg.entry.pid, pid);
261
262 if ((log_msg.entry.sec < (ts.tv_sec - 1))
263 || ((ts.tv_sec + 1) < log_msg.entry.sec)
264 || (log_msg.entry.len != (4 + 1 + 4))
265 || (log_msg.id() != LOG_ID_EVENTS)) {
266 continue;
267 }
268
269 char *eventData = log_msg.msg();
270
271 if (eventData[4] != EVENT_TYPE_STRING) {
272 continue;
273 }
274
275 int len = get4LE(eventData + 4 + 1);
276 if (len == 0) {
277 ++count;
278
279 AndroidLogFormat *logformat = android_log_format_new();
280 EXPECT_TRUE(NULL != logformat);
281 AndroidLogEntry entry;
282 char msgBuf[1024];
283 EXPECT_EQ(0, android_log_processBinaryLogBuffer(&log_msg.entry_v1,
284 &entry,
285 NULL,
286 msgBuf,
287 sizeof(msgBuf)));
288 fflush(stderr);
289 EXPECT_EQ(20, android_log_printLogLine(logformat, fileno(stderr), &entry));
290 android_log_format_free(logformat);
291 }
292 }
293
294 EXPECT_EQ(1, count);
295
296 android_logger_list_close(logger_list);
297}
298
Mark Salyzynffbd86f2015-12-04 10:59:45 -0800299TEST(liblog, __security) {
300 static const char persist_key[] = "persist.logd.security";
301 static const char readonly_key[] = "ro.device_owner";
302 static const char nothing_val[] = "_NOTHING_TO_SEE_HERE_";
303 char persist[PROP_VALUE_MAX];
304 char readonly[PROP_VALUE_MAX];
305
306 property_get(persist_key, persist, "");
307 property_get(readonly_key, readonly, nothing_val);
308
309 if (!strcmp(readonly, nothing_val)) {
310 EXPECT_FALSE(__android_log_security());
311 fprintf(stderr, "Warning, setting ro.device_owner to a domain\n");
312 property_set(readonly_key, "com.google.android.SecOps.DeviceOwner");
313 } else if (!strcasecmp(readonly, "false") || !readonly[0]) {
314 EXPECT_FALSE(__android_log_security());
315 return;
316 }
317
318 if (!strcasecmp(persist, "true")) {
319 EXPECT_TRUE(__android_log_security());
320 } else {
321 EXPECT_FALSE(__android_log_security());
322 }
323 property_set(persist_key, "TRUE");
324 EXPECT_TRUE(__android_log_security());
325 property_set(persist_key, "FALSE");
326 EXPECT_FALSE(__android_log_security());
327 property_set(persist_key, "true");
328 EXPECT_TRUE(__android_log_security());
329 property_set(persist_key, "false");
330 EXPECT_FALSE(__android_log_security());
331 property_set(persist_key, "");
332 EXPECT_FALSE(__android_log_security());
333 property_set(persist_key, persist);
334}
335
Mark Salyzyn083b0372015-12-04 10:59:45 -0800336TEST(liblog, __security_buffer) {
337 struct logger_list *logger_list;
338 android_event_long_t buffer;
339
340 static const char persist_key[] = "persist.logd.security";
341 char persist[PROP_VALUE_MAX];
342 bool set_persist = false;
343 bool allow_security = false;
344
345 if (__android_log_security()) {
346 allow_security = true;
347 } else {
348 property_get(persist_key, persist, "");
349 if (strcasecmp(persist, "true")) {
350 property_set(persist_key, "TRUE");
351 if (__android_log_security()) {
352 allow_security = true;
353 set_persist = true;
354 } else {
355 property_set(persist_key, persist);
356 }
357 }
358 }
359
360 if (!allow_security) {
361 fprintf(stderr, "WARNING: "
362 "security buffer disabled, bypassing end-to-end test\n");
363
364 log_time ts(CLOCK_MONOTONIC);
365
366 buffer.type = EVENT_TYPE_LONG;
367 buffer.data = *(static_cast<uint64_t *>((void *)&ts));
368
369 // expect failure!
370 ASSERT_GE(0, __android_log_security_bwrite(0, &buffer, sizeof(buffer)));
371
372 return;
373 }
374
Mark Salyzyn8fa88962016-01-26 14:32:35 -0800375 /* Matches clientHasLogCredentials() in logd */
376 uid_t uid = getuid();
377 gid_t gid = getgid();
378 bool clientHasLogCredentials = true;
379 if ((uid != AID_SYSTEM) && (uid != AID_ROOT) && (uid != AID_LOG)
380 && (gid != AID_SYSTEM) && (gid != AID_ROOT) && (gid != AID_LOG)) {
381 uid_t euid = geteuid();
382 if ((euid != AID_SYSTEM) && (euid != AID_ROOT) && (euid != AID_LOG)) {
383 gid_t egid = getegid();
384 if ((egid != AID_SYSTEM) && (egid != AID_ROOT) && (egid != AID_LOG)) {
385 int num_groups = getgroups(0, NULL);
386 if (num_groups > 0) {
387 gid_t groups[num_groups];
388 num_groups = getgroups(num_groups, groups);
389 while (num_groups > 0) {
390 if (groups[num_groups - 1] == AID_LOG) {
391 break;
392 }
393 --num_groups;
394 }
395 }
396 if (num_groups <= 0) {
397 clientHasLogCredentials = false;
398 }
399 }
400 }
401 }
402 if (!clientHasLogCredentials) {
403 fprintf(stderr, "WARNING: "
404 "not in system context, bypassing end-to-end test\n");
405
406 log_time ts(CLOCK_MONOTONIC);
407
408 buffer.type = EVENT_TYPE_LONG;
409 buffer.data = *(static_cast<uint64_t *>((void *)&ts));
410
411 // expect failure!
412 ASSERT_GE(0, __android_log_security_bwrite(0, &buffer, sizeof(buffer)));
413
414 return;
415 }
416
Mark Salyzyn083b0372015-12-04 10:59:45 -0800417 pid_t pid = getpid();
418
419 ASSERT_TRUE(NULL != (logger_list = android_logger_list_open(
420 LOG_ID_SECURITY, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK,
421 1000, pid)));
422
423 log_time ts(CLOCK_MONOTONIC);
424
425 buffer.type = EVENT_TYPE_LONG;
426 buffer.data = *(static_cast<uint64_t *>((void *)&ts));
427
428 ASSERT_LT(0, __android_log_security_bwrite(0, &buffer, sizeof(buffer)));
429 usleep(1000000);
430
431 int count = 0;
432
433 for (;;) {
434 log_msg log_msg;
435 if (android_logger_list_read(logger_list, &log_msg) <= 0) {
436 break;
437 }
438
439 ASSERT_EQ(log_msg.entry.pid, pid);
440
441 if ((log_msg.entry.len != (4 + 1 + 8))
442 || (log_msg.id() != LOG_ID_SECURITY)) {
443 continue;
444 }
445
446 char *eventData = log_msg.msg();
447
448 if (eventData[4] != EVENT_TYPE_LONG) {
449 continue;
450 }
451
452 log_time tx(eventData + 4 + 1);
453 if (ts == tx) {
454 ++count;
455 }
456 }
457
458 if (set_persist) {
459 property_set(persist_key, persist);
460 }
461
462 android_logger_list_close(logger_list);
463
Mark Salyzyn8fa88962016-01-26 14:32:35 -0800464 bool clientHasSecurityCredentials = (uid == AID_SYSTEM) || (gid == AID_SYSTEM);
465 if (!clientHasSecurityCredentials) {
466 fprintf(stderr, "WARNING: "
467 "not system, content submitted but can not check end-to-end\n");
468 }
469 EXPECT_EQ(clientHasSecurityCredentials ? 1 : 0, count);
Mark Salyzyn083b0372015-12-04 10:59:45 -0800470
471}
472
Mark Salyzyncef098e2014-01-09 09:02:55 -0800473static unsigned signaled;
Mark Salyzyna6f2f812016-03-10 15:25:14 -0800474static log_time signal_time;
Mark Salyzyncef098e2014-01-09 09:02:55 -0800475
Mark Salyzyna6f2f812016-03-10 15:25:14 -0800476/*
477 * Strictly, we are not allowed to log messages in a signal context, but we
478 * do make an effort to keep the failure surface minimized, and this in-effect
479 * should catch any regressions in that effort. The odds of a logged message
480 * in a signal handler causing a lockup problem should be _very_ small.
481 */
482static void caught_blocking_signal(int /*signum*/)
Mark Salyzyncef098e2014-01-09 09:02:55 -0800483{
484 unsigned long long v = 0xDEADBEEFA55A0000ULL;
485
486 v += getpid() & 0xFFFF;
487
488 ++signaled;
489 if ((signal_time.tv_sec == 0) && (signal_time.tv_nsec == 0)) {
Mark Salyzyn7e2f83c2014-03-05 07:41:49 -0800490 signal_time = log_time(CLOCK_MONOTONIC);
Mark Salyzyncef098e2014-01-09 09:02:55 -0800491 signal_time.tv_sec += 2;
492 }
493
494 LOG_FAILURE_RETRY(__android_log_btwrite(0, EVENT_TYPE_LONG, &v, sizeof(v)));
495}
496
497// Fill in current process user and system time in 10ms increments
498static void get_ticks(unsigned long long *uticks, unsigned long long *sticks)
499{
500 *uticks = *sticks = 0;
501
502 pid_t pid = getpid();
503
504 char buffer[512];
505 snprintf(buffer, sizeof(buffer), "/proc/%u/stat", pid);
506
507 FILE *fp = fopen(buffer, "r");
508 if (!fp) {
509 return;
510 }
511
512 char *cp = fgets(buffer, sizeof(buffer), fp);
513 fclose(fp);
514 if (!cp) {
515 return;
516 }
517
518 pid_t d;
519 char s[sizeof(buffer)];
520 char c;
521 long long ll;
522 unsigned long long ull;
523
524 if (15 != sscanf(buffer,
525 "%d %s %c %lld %lld %lld %lld %lld %llu %llu %llu %llu %llu %llu %llu ",
526 &d, s, &c, &ll, &ll, &ll, &ll, &ll, &ull, &ull, &ull, &ull, &ull,
527 uticks, sticks)) {
528 *uticks = *sticks = 0;
529 }
530}
531
Mark Salyzyna6f2f812016-03-10 15:25:14 -0800532TEST(liblog, android_logger_list_read__cpu_signal) {
Mark Salyzyncef098e2014-01-09 09:02:55 -0800533 struct logger_list *logger_list;
534 unsigned long long v = 0xDEADBEEFA55A0000ULL;
535
536 pid_t pid = getpid();
537
538 v += pid & 0xFFFF;
539
Mark Salyzyn8196be32014-03-18 17:10:47 -0700540 ASSERT_TRUE(NULL != (logger_list = android_logger_list_open(
Mark Salyzyn2d3f38a2015-01-26 10:46:44 -0800541 LOG_ID_EVENTS, ANDROID_LOG_RDONLY, 1000, pid)));
Mark Salyzyncef098e2014-01-09 09:02:55 -0800542
543 int count = 0;
544
545 int signals = 0;
546
547 unsigned long long uticks_start;
548 unsigned long long sticks_start;
549 get_ticks(&uticks_start, &sticks_start);
550
551 const unsigned alarm_time = 10;
552
553 memset(&signal_time, 0, sizeof(signal_time));
554
Mark Salyzyna6f2f812016-03-10 15:25:14 -0800555 signal(SIGALRM, caught_blocking_signal);
Mark Salyzyncef098e2014-01-09 09:02:55 -0800556 alarm(alarm_time);
557
558 signaled = 0;
559
560 do {
561 log_msg log_msg;
562 if (android_logger_list_read(logger_list, &log_msg) <= 0) {
563 break;
564 }
565
566 alarm(alarm_time);
567
568 ++count;
569
570 ASSERT_EQ(log_msg.entry.pid, pid);
571
572 if ((log_msg.entry.len != (4 + 1 + 8))
573 || (log_msg.id() != LOG_ID_EVENTS)) {
574 continue;
575 }
576
577 char *eventData = log_msg.msg();
578
579 if (eventData[4] != EVENT_TYPE_LONG) {
580 continue;
581 }
582
583 unsigned long long l = eventData[4 + 1 + 0] & 0xFF;
584 l |= (unsigned long long) (eventData[4 + 1 + 1] & 0xFF) << 8;
585 l |= (unsigned long long) (eventData[4 + 1 + 2] & 0xFF) << 16;
586 l |= (unsigned long long) (eventData[4 + 1 + 3] & 0xFF) << 24;
587 l |= (unsigned long long) (eventData[4 + 1 + 4] & 0xFF) << 32;
588 l |= (unsigned long long) (eventData[4 + 1 + 5] & 0xFF) << 40;
589 l |= (unsigned long long) (eventData[4 + 1 + 6] & 0xFF) << 48;
590 l |= (unsigned long long) (eventData[4 + 1 + 7] & 0xFF) << 56;
591
592 if (l == v) {
593 ++signals;
594 break;
595 }
Mark Salyzyn8196be32014-03-18 17:10:47 -0700596 } while (!signaled || (log_time(CLOCK_MONOTONIC) < signal_time));
Mark Salyzyncef098e2014-01-09 09:02:55 -0800597 alarm(0);
598 signal(SIGALRM, SIG_DFL);
599
Mark Salyzyna6f2f812016-03-10 15:25:14 -0800600 EXPECT_LE(1, count);
601
602 EXPECT_EQ(1, signals);
603
604 android_logger_list_close(logger_list);
605
606 unsigned long long uticks_end;
607 unsigned long long sticks_end;
608 get_ticks(&uticks_end, &sticks_end);
609
610 // Less than 1% in either user or system time, or both
611 const unsigned long long one_percent_ticks = alarm_time;
612 unsigned long long user_ticks = uticks_end - uticks_start;
613 unsigned long long system_ticks = sticks_end - sticks_start;
614 EXPECT_GT(one_percent_ticks, user_ticks);
615 EXPECT_GT(one_percent_ticks, system_ticks);
616 EXPECT_GT(one_percent_ticks, user_ticks + system_ticks);
617}
618
619/*
620 * Strictly, we are not allowed to log messages in a signal context, the
621 * correct way to handle this is to ensure the messages are constructed in
622 * a thread; the signal handler should only unblock the thread.
623 */
624static sem_t thread_trigger;
625
626static void caught_blocking_thread(int /*signum*/)
627{
628 sem_post(&thread_trigger);
629}
630
631static void *running_thread(void *) {
632 unsigned long long v = 0xDEADBEAFA55A0000ULL;
633
634 v += getpid() & 0xFFFF;
635
636 struct timespec timeout;
637 clock_gettime(CLOCK_REALTIME, &timeout);
638 timeout.tv_sec += 55;
639 sem_timedwait(&thread_trigger, &timeout);
640
641 ++signaled;
642 if ((signal_time.tv_sec == 0) && (signal_time.tv_nsec == 0)) {
643 signal_time = log_time(CLOCK_MONOTONIC);
644 signal_time.tv_sec += 2;
645 }
646
647 LOG_FAILURE_RETRY(__android_log_btwrite(0, EVENT_TYPE_LONG, &v, sizeof(v)));
648
649 return NULL;
650}
651
652int start_thread()
653{
654 sem_init(&thread_trigger, 0, 0);
655
656 pthread_attr_t attr;
657 if (pthread_attr_init(&attr)) {
658 return -1;
659 }
660
661 struct sched_param param;
662
663 memset(&param, 0, sizeof(param));
664 pthread_attr_setschedparam(&attr, &param);
665 pthread_attr_setschedpolicy(&attr, SCHED_BATCH);
666
667 if (pthread_attr_setdetachstate(&attr, PTHREAD_CREATE_DETACHED)) {
668 pthread_attr_destroy(&attr);
669 return -1;
670 }
671
672 pthread_t thread;
673 if (pthread_create(&thread, &attr, running_thread, NULL)) {
674 pthread_attr_destroy(&attr);
675 return -1;
676 }
677
678 pthread_attr_destroy(&attr);
679 return 0;
680}
681
682TEST(liblog, android_logger_list_read__cpu_thread) {
683 struct logger_list *logger_list;
684 unsigned long long v = 0xDEADBEAFA55A0000ULL;
685
686 pid_t pid = getpid();
687
688 v += pid & 0xFFFF;
689
690 ASSERT_TRUE(NULL != (logger_list = android_logger_list_open(
691 LOG_ID_EVENTS, ANDROID_LOG_RDONLY, 1000, pid)));
692
693 int count = 0;
694
695 int signals = 0;
696
697 unsigned long long uticks_start;
698 unsigned long long sticks_start;
699 get_ticks(&uticks_start, &sticks_start);
700
701 const unsigned alarm_time = 10;
702
703 memset(&signal_time, 0, sizeof(signal_time));
704
705 signaled = 0;
706 EXPECT_EQ(0, start_thread());
707
708 signal(SIGALRM, caught_blocking_thread);
709 alarm(alarm_time);
710
711 do {
712 log_msg log_msg;
713 if (LOG_FAILURE_RETRY(android_logger_list_read(logger_list, &log_msg)) <= 0) {
714 break;
715 }
716
717 alarm(alarm_time);
718
719 ++count;
720
721 ASSERT_EQ(log_msg.entry.pid, pid);
722
723 if ((log_msg.entry.len != (4 + 1 + 8))
724 || (log_msg.id() != LOG_ID_EVENTS)) {
725 continue;
726 }
727
728 char *eventData = log_msg.msg();
729
730 if (eventData[4] != EVENT_TYPE_LONG) {
731 continue;
732 }
733
734 unsigned long long l = eventData[4 + 1 + 0] & 0xFF;
735 l |= (unsigned long long) (eventData[4 + 1 + 1] & 0xFF) << 8;
736 l |= (unsigned long long) (eventData[4 + 1 + 2] & 0xFF) << 16;
737 l |= (unsigned long long) (eventData[4 + 1 + 3] & 0xFF) << 24;
738 l |= (unsigned long long) (eventData[4 + 1 + 4] & 0xFF) << 32;
739 l |= (unsigned long long) (eventData[4 + 1 + 5] & 0xFF) << 40;
740 l |= (unsigned long long) (eventData[4 + 1 + 6] & 0xFF) << 48;
741 l |= (unsigned long long) (eventData[4 + 1 + 7] & 0xFF) << 56;
742
743 if (l == v) {
744 ++signals;
745 break;
746 }
747 } while (!signaled || (log_time(CLOCK_MONOTONIC) < signal_time));
748 alarm(0);
749 signal(SIGALRM, SIG_DFL);
750
751 EXPECT_LE(1, count);
Mark Salyzyncef098e2014-01-09 09:02:55 -0800752
Mark Salyzyn8196be32014-03-18 17:10:47 -0700753 EXPECT_EQ(1, signals);
Mark Salyzyncef098e2014-01-09 09:02:55 -0800754
755 android_logger_list_close(logger_list);
756
757 unsigned long long uticks_end;
758 unsigned long long sticks_end;
759 get_ticks(&uticks_end, &sticks_end);
760
761 // Less than 1% in either user or system time, or both
762 const unsigned long long one_percent_ticks = alarm_time;
763 unsigned long long user_ticks = uticks_end - uticks_start;
764 unsigned long long system_ticks = sticks_end - sticks_start;
Mark Salyzyn8196be32014-03-18 17:10:47 -0700765 EXPECT_GT(one_percent_ticks, user_ticks);
766 EXPECT_GT(one_percent_ticks, system_ticks);
767 EXPECT_GT(one_percent_ticks, user_ticks + system_ticks);
768}
769
770static const char max_payload_tag[] = "TEST_max_payload_XXXX";
Mark Salyzyn42ae8272015-12-03 15:37:00 -0800771#define SIZEOF_MAX_PAYLOAD_BUF (LOGGER_ENTRY_MAX_PAYLOAD - \
772 sizeof(max_payload_tag) - 1)
773static const char max_payload_buf[] = "LEONATO\n\
Mark Salyzyn8196be32014-03-18 17:10:47 -0700774I learn in this letter that Don Peter of Arragon\n\
775comes this night to Messina\n\
776MESSENGER\n\
777He is very near by this: he was not three leagues off\n\
778when I left him\n\
779LEONATO\n\
780How many gentlemen have you lost in this action?\n\
781MESSENGER\n\
782But few of any sort, and none of name\n\
783LEONATO\n\
784A victory is twice itself when the achiever brings\n\
785home full numbers. I find here that Don Peter hath\n\
786bestowed much honour on a young Florentine called Claudio\n\
787MESSENGER\n\
788Much deserved on his part and equally remembered by\n\
789Don Pedro: he hath borne himself beyond the\n\
790promise of his age, doing, in the figure of a lamb,\n\
791the feats of a lion: he hath indeed better\n\
792bettered expectation than you must expect of me to\n\
793tell you how\n\
794LEONATO\n\
795He hath an uncle here in Messina will be very much\n\
796glad of it.\n\
797MESSENGER\n\
798I have already delivered him letters, and there\n\
799appears much joy in him; even so much that joy could\n\
800not show itself modest enough without a badge of\n\
801bitterness.\n\
802LEONATO\n\
803Did he break out into tears?\n\
804MESSENGER\n\
805In great measure.\n\
806LEONATO\n\
807A kind overflow of kindness: there are no faces\n\
808truer than those that are so washed. How much\n\
809better is it to weep at joy than to joy at weeping!\n\
810BEATRICE\n\
811I pray you, is Signior Mountanto returned from the\n\
812wars or no?\n\
813MESSENGER\n\
814I know none of that name, lady: there was none such\n\
815in the army of any sort.\n\
816LEONATO\n\
817What is he that you ask for, niece?\n\
818HERO\n\
819My cousin means Signior Benedick of Padua.\n\
820MESSENGER\n\
821O, he's returned; and as pleasant as ever he was.\n\
822BEATRICE\n\
823He set up his bills here in Messina and challenged\n\
824Cupid at the flight; and my uncle's fool, reading\n\
825the challenge, subscribed for Cupid, and challenged\n\
826him at the bird-bolt. I pray you, how many hath he\n\
827killed and eaten in these wars? But how many hath\n\
828he killed? for indeed I promised to eat all of his killing.\n\
829LEONATO\n\
830Faith, niece, you tax Signior Benedick too much;\n\
831but he'll be meet with you, I doubt it not.\n\
832MESSENGER\n\
833He hath done good service, lady, in these wars.\n\
834BEATRICE\n\
835You had musty victual, and he hath holp to eat it:\n\
836he is a very valiant trencherman; he hath an\n\
837excellent stomach.\n\
838MESSENGER\n\
839And a good soldier too, lady.\n\
840BEATRICE\n\
841And a good soldier to a lady: but what is he to a lord?\n\
842MESSENGER\n\
843A lord to a lord, a man to a man; stuffed with all\n\
844honourable virtues.\n\
845BEATRICE\n\
846It is so, indeed; he is no less than a stuffed man:\n\
847but for the stuffing,--well, we are all mortal.\n\
848LEONATO\n\
849You must not, sir, mistake my niece. There is a\n\
850kind of merry war betwixt Signior Benedick and her:\n\
851they never meet but there's a skirmish of wit\n\
852between them.\n\
853BEATRICE\n\
854Alas! he gets nothing by that. In our last\n\
855conflict four of his five wits went halting off, and\n\
856now is the whole man governed with one: so that if\n\
857he have wit enough to keep himself warm, let him\n\
858bear it for a difference between himself and his\n\
859horse; for it is all the wealth that he hath left,\n\
860to be known a reasonable creature. Who is his\n\
861companion now? He hath every month a new sworn brother.\n\
862MESSENGER\n\
863Is't possible?\n\
864BEATRICE\n\
865Very easily possible: he wears his faith but as\n\
866the fashion of his hat; it ever changes with the\n\
867next block.\n\
868MESSENGER\n\
869I see, lady, the gentleman is not in your books.\n\
870BEATRICE\n\
871No; an he were, I would burn my study. But, I pray\n\
872you, who is his companion? Is there no young\n\
873squarer now that will make a voyage with him to the devil?\n\
874MESSENGER\n\
875He is most in the company of the right noble Claudio.\n\
876BEATRICE\n\
877O Lord, he will hang upon him like a disease: he\n\
878is sooner caught than the pestilence, and the taker\n\
879runs presently mad. God help the noble Claudio! if\n\
880he have caught the Benedick, it will cost him a\n\
881thousand pound ere a' be cured.\n\
882MESSENGER\n\
883I will hold friends with you, lady.\n\
884BEATRICE\n\
885Do, good friend.\n\
886LEONATO\n\
887You will never run mad, niece.\n\
888BEATRICE\n\
889No, not till a hot January.\n\
890MESSENGER\n\
891Don Pedro is approached.\n\
892Enter DON PEDRO, DON JOHN, CLAUDIO, BENEDICK, and BALTHASAR\n\
893\n\
894DON PEDRO\n\
895Good Signior Leonato, you are come to meet your\n\
896trouble: the fashion of the world is to avoid\n\
897cost, and you encounter it\n\
898LEONATO\n\
Mark Salyzyn10bdf612016-03-10 09:50:08 -0800899Never came trouble to my house in the likeness of your grace,\n\
900for trouble being gone, comfort should remain, but\n\
901when you depart from me, sorrow abides and happiness\n\
902takes his leave.";
Mark Salyzyn8196be32014-03-18 17:10:47 -0700903
904TEST(liblog, max_payload) {
905 pid_t pid = getpid();
906 char tag[sizeof(max_payload_tag)];
907 memcpy(tag, max_payload_tag, sizeof(tag));
908 snprintf(tag + sizeof(tag) - 5, 5, "%04X", pid & 0xFFFF);
909
910 LOG_FAILURE_RETRY(__android_log_buf_write(LOG_ID_SYSTEM, ANDROID_LOG_INFO,
911 tag, max_payload_buf));
Mark Salyzync1584562015-03-12 15:46:29 -0700912 sleep(2);
Mark Salyzyn8196be32014-03-18 17:10:47 -0700913
914 struct logger_list *logger_list;
915
916 ASSERT_TRUE(NULL != (logger_list = android_logger_list_open(
Mark Salyzyn2d3f38a2015-01-26 10:46:44 -0800917 LOG_ID_SYSTEM, ANDROID_LOG_RDONLY, 100, 0)));
Mark Salyzyn8196be32014-03-18 17:10:47 -0700918
919 bool matches = false;
920 ssize_t max_len = 0;
921
922 for(;;) {
923 log_msg log_msg;
924 if (android_logger_list_read(logger_list, &log_msg) <= 0) {
925 break;
926 }
927
928 if ((log_msg.entry.pid != pid) || (log_msg.id() != LOG_ID_SYSTEM)) {
929 continue;
930 }
931
932 char *data = log_msg.msg() + 1;
933
934 if (strcmp(data, tag)) {
935 continue;
936 }
937
938 data += strlen(data) + 1;
939
940 const char *left = data;
941 const char *right = max_payload_buf;
942 while (*left && *right && (*left == *right)) {
943 ++left;
944 ++right;
945 }
946
947 if (max_len <= (left - data)) {
948 max_len = left - data + 1;
949 }
950
951 if (max_len > 512) {
952 matches = true;
953 break;
954 }
955 }
956
Mark Salyzyn8444eb82014-04-24 09:43:23 -0700957 android_logger_list_close(logger_list);
958
Mark Salyzyn8196be32014-03-18 17:10:47 -0700959 EXPECT_EQ(true, matches);
960
Mark Salyzyn42ae8272015-12-03 15:37:00 -0800961 EXPECT_LE(SIZEOF_MAX_PAYLOAD_BUF, static_cast<size_t>(max_len));
Mark Salyzyn8444eb82014-04-24 09:43:23 -0700962}
963
Mark Salyzyn73207ce2016-03-11 12:06:12 -0800964TEST(liblog, __android_log_buf_print__maxtag) {
965 struct logger_list *logger_list;
966
967 pid_t pid = getpid();
968
969 ASSERT_TRUE(NULL != (logger_list = android_logger_list_open(
970 LOG_ID_MAIN, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 1000, pid)));
971
972 log_time ts(android_log_clockid());
973
974 EXPECT_LT(0, __android_log_buf_print(LOG_ID_MAIN, ANDROID_LOG_INFO,
975 max_payload_buf, max_payload_buf));
976 usleep(1000000);
977
978 int count = 0;
979
980 for (;;) {
981 log_msg log_msg;
982 if (android_logger_list_read(logger_list, &log_msg) <= 0) {
983 break;
984 }
985
986 ASSERT_EQ(log_msg.entry.pid, pid);
987
988 if ((log_msg.entry.sec < (ts.tv_sec - 1))
989 || ((ts.tv_sec + 1) < log_msg.entry.sec)
990 || ((size_t)log_msg.entry.len < LOGGER_ENTRY_MAX_PAYLOAD)
991 || (log_msg.id() != LOG_ID_MAIN)) {
992 continue;
993 }
994
995 ++count;
996
997 AndroidLogFormat *logformat = android_log_format_new();
998 EXPECT_TRUE(NULL != logformat);
999 AndroidLogEntry entry;
1000 int processLogBuffer = android_log_processLogBuffer(&log_msg.entry_v1,
1001 &entry);
1002 EXPECT_EQ(0, processLogBuffer);
1003 if (processLogBuffer == 0) {
1004 fflush(stderr);
1005 int printLogLine =
1006 android_log_printLogLine(logformat, fileno(stderr), &entry);
Mark Salyzyn476b7712016-03-21 09:45:34 -07001007 // Legacy tag truncation
Mark Salyzyn73207ce2016-03-11 12:06:12 -08001008 EXPECT_LE(128, printLogLine);
Mark Salyzyn476b7712016-03-21 09:45:34 -07001009 // Measured maximum if we try to print part of the tag as message
1010 EXPECT_GT(LOGGER_ENTRY_MAX_PAYLOAD * 13 / 8, printLogLine);
Mark Salyzyn73207ce2016-03-11 12:06:12 -08001011 }
1012 android_log_format_free(logformat);
1013 }
1014
1015 EXPECT_EQ(1, count);
1016
1017 android_logger_list_close(logger_list);
1018}
1019
Mark Salyzyn8444eb82014-04-24 09:43:23 -07001020TEST(liblog, too_big_payload) {
1021 pid_t pid = getpid();
1022 static const char big_payload_tag[] = "TEST_big_payload_XXXX";
1023 char tag[sizeof(big_payload_tag)];
1024 memcpy(tag, big_payload_tag, sizeof(tag));
1025 snprintf(tag + sizeof(tag) - 5, 5, "%04X", pid & 0xFFFF);
1026
1027 std::string longString(3266519, 'x');
1028
1029 ssize_t ret = LOG_FAILURE_RETRY(__android_log_buf_write(LOG_ID_SYSTEM,
1030 ANDROID_LOG_INFO, tag, longString.c_str()));
1031
1032 struct logger_list *logger_list;
1033
1034 ASSERT_TRUE(NULL != (logger_list = android_logger_list_open(
Mark Salyzyn2d3f38a2015-01-26 10:46:44 -08001035 LOG_ID_SYSTEM, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 100, 0)));
Mark Salyzyn8444eb82014-04-24 09:43:23 -07001036
1037 ssize_t max_len = 0;
1038
1039 for(;;) {
1040 log_msg log_msg;
1041 if (android_logger_list_read(logger_list, &log_msg) <= 0) {
1042 break;
1043 }
1044
1045 if ((log_msg.entry.pid != pid) || (log_msg.id() != LOG_ID_SYSTEM)) {
1046 continue;
1047 }
1048
1049 char *data = log_msg.msg() + 1;
1050
1051 if (strcmp(data, tag)) {
1052 continue;
1053 }
1054
1055 data += strlen(data) + 1;
1056
1057 const char *left = data;
1058 const char *right = longString.c_str();
1059 while (*left && *right && (*left == *right)) {
1060 ++left;
1061 ++right;
1062 }
1063
1064 if (max_len <= (left - data)) {
1065 max_len = left - data + 1;
1066 }
1067 }
Mark Salyzyn8196be32014-03-18 17:10:47 -07001068
1069 android_logger_list_close(logger_list);
Mark Salyzyn8444eb82014-04-24 09:43:23 -07001070
1071 EXPECT_LE(LOGGER_ENTRY_MAX_PAYLOAD - sizeof(big_payload_tag),
1072 static_cast<size_t>(max_len));
1073
Ben Cheng43232922014-05-20 10:38:24 -07001074 EXPECT_EQ(ret, max_len + static_cast<ssize_t>(sizeof(big_payload_tag)));
Mark Salyzyn8196be32014-03-18 17:10:47 -07001075}
1076
1077TEST(liblog, dual_reader) {
1078 struct logger_list *logger_list1;
1079
1080 // >25 messages due to liblog.__android_log_buf_print__concurrentXX above.
1081 ASSERT_TRUE(NULL != (logger_list1 = android_logger_list_open(
Mark Salyzyn2d3f38a2015-01-26 10:46:44 -08001082 LOG_ID_MAIN, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 25, 0)));
Mark Salyzyn8196be32014-03-18 17:10:47 -07001083
1084 struct logger_list *logger_list2;
1085
1086 if (NULL == (logger_list2 = android_logger_list_open(
Mark Salyzyn2d3f38a2015-01-26 10:46:44 -08001087 LOG_ID_MAIN, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 15, 0))) {
Mark Salyzyn8196be32014-03-18 17:10:47 -07001088 android_logger_list_close(logger_list1);
1089 ASSERT_TRUE(NULL != logger_list2);
1090 }
1091
1092 int count1 = 0;
1093 bool done1 = false;
1094 int count2 = 0;
1095 bool done2 = false;
1096
1097 do {
1098 log_msg log_msg;
1099
1100 if (!done1) {
1101 if (android_logger_list_read(logger_list1, &log_msg) <= 0) {
1102 done1 = true;
1103 } else {
1104 ++count1;
1105 }
1106 }
1107
1108 if (!done2) {
1109 if (android_logger_list_read(logger_list2, &log_msg) <= 0) {
1110 done2 = true;
1111 } else {
1112 ++count2;
1113 }
1114 }
1115 } while ((!done1) || (!done2));
1116
1117 android_logger_list_close(logger_list1);
1118 android_logger_list_close(logger_list2);
1119
1120 EXPECT_EQ(25, count1);
1121 EXPECT_EQ(15, count2);
Mark Salyzyncef098e2014-01-09 09:02:55 -08001122}
1123
Mark Salyzyn819c58a2013-11-22 12:39:43 -08001124TEST(liblog, android_logger_get_) {
Mark Salyzyn2d3f38a2015-01-26 10:46:44 -08001125 struct logger_list * logger_list = android_logger_list_alloc(ANDROID_LOG_WRONLY, 0, 0);
Mark Salyzyn819c58a2013-11-22 12:39:43 -08001126
1127 for(int i = LOG_ID_MIN; i < LOG_ID_MAX; ++i) {
1128 log_id_t id = static_cast<log_id_t>(i);
1129 const char *name = android_log_id_to_name(id);
1130 if (id != android_name_to_log_id(name)) {
1131 continue;
1132 }
Mark Salyzync1584562015-03-12 15:46:29 -07001133 fprintf(stderr, "log buffer %s\r", name);
Mark Salyzyn819c58a2013-11-22 12:39:43 -08001134 struct logger * logger;
Mark Salyzyn8196be32014-03-18 17:10:47 -07001135 EXPECT_TRUE(NULL != (logger = android_logger_open(logger_list, id)));
1136 EXPECT_EQ(id, android_logger_get_id(logger));
Mark Salyzyn53263ff2016-03-10 15:25:14 -08001137 ssize_t get_log_size = android_logger_get_log_size(logger);
1138 /* security buffer is allowed to be denied */
1139 if (strcmp("security", name)) {
1140 EXPECT_LT(0, get_log_size);
1141 /* crash buffer is allowed to be empty, that is actually healthy! */
1142 EXPECT_LE((strcmp("crash", name)) != 0,
1143 android_logger_get_log_readable_size(logger));
1144 } else {
1145 EXPECT_NE(0, get_log_size);
1146 if (get_log_size < 0) {
1147 EXPECT_GT(0, android_logger_get_log_readable_size(logger));
1148 } else {
1149 EXPECT_LE(0, android_logger_get_log_readable_size(logger));
1150 }
Mark Salyzync1584562015-03-12 15:46:29 -07001151 }
Mark Salyzyn8196be32014-03-18 17:10:47 -07001152 EXPECT_LT(0, android_logger_get_log_version(logger));
Mark Salyzyn819c58a2013-11-22 12:39:43 -08001153 }
1154
1155 android_logger_list_close(logger_list);
1156}
Mark Salyzyn5045f572014-04-30 08:50:53 -07001157
1158static bool checkPriForTag(AndroidLogFormat *p_format, const char *tag, android_LogPriority pri) {
1159 return android_log_shouldPrintLine(p_format, tag, pri)
1160 && !android_log_shouldPrintLine(p_format, tag, (android_LogPriority)(pri - 1));
1161}
1162
1163TEST(liblog, filterRule) {
1164 static const char tag[] = "random";
1165
1166 AndroidLogFormat *p_format = android_log_format_new();
1167
1168 android_log_addFilterRule(p_format,"*:i");
1169
1170 EXPECT_TRUE(checkPriForTag(p_format, tag, ANDROID_LOG_INFO));
1171 EXPECT_TRUE(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) == 0);
1172 android_log_addFilterRule(p_format, "*");
1173 EXPECT_TRUE (checkPriForTag(p_format, tag, ANDROID_LOG_DEBUG));
1174 EXPECT_TRUE(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) > 0);
1175 android_log_addFilterRule(p_format, "*:v");
1176 EXPECT_TRUE (checkPriForTag(p_format, tag, ANDROID_LOG_VERBOSE));
1177 EXPECT_TRUE(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) > 0);
1178 android_log_addFilterRule(p_format, "*:i");
1179 EXPECT_TRUE (checkPriForTag(p_format, tag, ANDROID_LOG_INFO));
1180 EXPECT_TRUE(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) == 0);
1181
1182 android_log_addFilterRule(p_format, tag);
1183 EXPECT_TRUE (checkPriForTag(p_format, tag, ANDROID_LOG_VERBOSE));
1184 EXPECT_TRUE(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) > 0);
1185 android_log_addFilterRule(p_format, "random:v");
1186 EXPECT_TRUE (checkPriForTag(p_format, tag, ANDROID_LOG_VERBOSE));
1187 EXPECT_TRUE(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) > 0);
1188 android_log_addFilterRule(p_format, "random:d");
1189 EXPECT_TRUE (checkPriForTag(p_format, tag, ANDROID_LOG_DEBUG));
1190 EXPECT_TRUE(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) > 0);
1191 android_log_addFilterRule(p_format, "random:w");
1192 EXPECT_TRUE (checkPriForTag(p_format, tag, ANDROID_LOG_WARN));
1193 EXPECT_TRUE(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) == 0);
1194
1195 android_log_addFilterRule(p_format, "crap:*");
1196 EXPECT_TRUE (checkPriForTag(p_format, "crap", ANDROID_LOG_VERBOSE));
1197 EXPECT_TRUE(android_log_shouldPrintLine(p_format, "crap", ANDROID_LOG_VERBOSE) > 0);
1198
1199 // invalid expression
1200 EXPECT_TRUE (android_log_addFilterRule(p_format, "random:z") < 0);
1201 EXPECT_TRUE (checkPriForTag(p_format, tag, ANDROID_LOG_WARN));
1202 EXPECT_TRUE(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) == 0);
1203
1204 // Issue #550946
1205 EXPECT_TRUE(android_log_addFilterString(p_format, " ") == 0);
1206 EXPECT_TRUE(checkPriForTag(p_format, tag, ANDROID_LOG_WARN));
1207
1208 // note trailing space
1209 EXPECT_TRUE(android_log_addFilterString(p_format, "*:s random:d ") == 0);
1210 EXPECT_TRUE(checkPriForTag(p_format, tag, ANDROID_LOG_DEBUG));
1211
1212 EXPECT_TRUE(android_log_addFilterString(p_format, "*:s random:z") < 0);
1213
1214#if 0 // bitrot, seek update
1215 char defaultBuffer[512];
1216
1217 android_log_formatLogLine(p_format,
1218 defaultBuffer, sizeof(defaultBuffer), 0, ANDROID_LOG_ERROR, 123,
1219 123, 123, tag, "nofile", strlen("Hello"), "Hello", NULL);
1220
1221 fprintf(stderr, "%s\n", defaultBuffer);
1222#endif
1223
1224 android_log_format_free(p_format);
1225}
Mark Salyzync1584562015-03-12 15:46:29 -07001226
1227TEST(liblog, is_loggable) {
1228 static const char tag[] = "is_loggable";
1229 static const char log_namespace[] = "persist.log.tag.";
1230 static const size_t base_offset = 8; /* skip "persist." */
1231 // sizeof("string") = strlen("string") + 1
1232 char key[sizeof(log_namespace) + sizeof(tag) - 1];
1233 char hold[4][PROP_VALUE_MAX];
1234 static const struct {
1235 int level;
1236 char type;
1237 } levels[] = {
1238 { ANDROID_LOG_VERBOSE, 'v' },
1239 { ANDROID_LOG_DEBUG , 'd' },
1240 { ANDROID_LOG_INFO , 'i' },
1241 { ANDROID_LOG_WARN , 'w' },
1242 { ANDROID_LOG_ERROR , 'e' },
1243 { ANDROID_LOG_FATAL , 'a' },
1244 { -1 , 's' },
1245 { -2 , 'g' }, // Illegal value, resort to default
1246 };
1247
1248 // Set up initial test condition
1249 memset(hold, 0, sizeof(hold));
1250 snprintf(key, sizeof(key), "%s%s", log_namespace, tag);
1251 property_get(key, hold[0], "");
1252 property_set(key, "");
1253 property_get(key + base_offset, hold[1], "");
1254 property_set(key + base_offset, "");
1255 strcpy(key, log_namespace);
1256 key[sizeof(log_namespace) - 2] = '\0';
1257 property_get(key, hold[2], "");
1258 property_set(key, "");
1259 property_get(key, hold[3], "");
1260 property_set(key + base_offset, "");
1261
1262 // All combinations of level and defaults
1263 for(size_t i = 0; i < (sizeof(levels) / sizeof(levels[0])); ++i) {
1264 if (levels[i].level == -2) {
1265 continue;
1266 }
1267 for(size_t j = 0; j < (sizeof(levels) / sizeof(levels[0])); ++j) {
1268 if (levels[j].level == -2) {
1269 continue;
1270 }
1271 fprintf(stderr, "i=%zu j=%zu\r", i, j);
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001272 bool android_log_is_loggable = __android_log_is_loggable(
1273 levels[i].level, tag, levels[j].level);
Mark Salyzync1584562015-03-12 15:46:29 -07001274 if ((levels[i].level < levels[j].level)
1275 || (levels[j].level == -1)) {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001276 if (android_log_is_loggable) {
1277 fprintf(stderr, "\n");
1278 }
1279 EXPECT_FALSE(android_log_is_loggable);
Mark Salyzyn504daa62016-04-14 15:31:56 -07001280 for(size_t k = 10; k; --k) {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001281 EXPECT_FALSE(__android_log_is_loggable(
1282 levels[i].level, tag, levels[j].level));
1283 }
Mark Salyzync1584562015-03-12 15:46:29 -07001284 } else {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001285 if (!android_log_is_loggable) {
1286 fprintf(stderr, "\n");
1287 }
1288 EXPECT_TRUE(android_log_is_loggable);
Mark Salyzyn504daa62016-04-14 15:31:56 -07001289 for(size_t k = 10; k; --k) {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001290 EXPECT_TRUE(__android_log_is_loggable(
1291 levels[i].level, tag, levels[j].level));
1292 }
Mark Salyzync1584562015-03-12 15:46:29 -07001293 }
1294 }
1295 }
1296
1297 // All combinations of level and tag and global properties
1298 for(size_t i = 0; i < (sizeof(levels) / sizeof(levels[0])); ++i) {
1299 if (levels[i].level == -2) {
1300 continue;
1301 }
1302 for(size_t j = 0; j < (sizeof(levels) / sizeof(levels[0])); ++j) {
1303 char buf[2];
1304 buf[0] = levels[j].type;
1305 buf[1] = '\0';
1306
1307 snprintf(key, sizeof(key), "%s%s", log_namespace, tag);
1308 fprintf(stderr, "i=%zu j=%zu property_set(\"%s\",\"%s\")\r",
1309 i, j, key, buf);
1310 property_set(key, buf);
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001311 bool android_log_is_loggable = __android_log_is_loggable(
1312 levels[i].level, tag, ANDROID_LOG_DEBUG);
Mark Salyzync1584562015-03-12 15:46:29 -07001313 if ((levels[i].level < levels[j].level)
1314 || (levels[j].level == -1)
1315 || ((levels[i].level < ANDROID_LOG_DEBUG)
1316 && (levels[j].level == -2))) {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001317 if (android_log_is_loggable) {
1318 fprintf(stderr, "\n");
1319 }
1320 EXPECT_FALSE(android_log_is_loggable);
Mark Salyzyn504daa62016-04-14 15:31:56 -07001321 for(size_t k = 10; k; --k) {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001322 EXPECT_FALSE(__android_log_is_loggable(
1323 levels[i].level, tag, ANDROID_LOG_DEBUG));
1324 }
Mark Salyzync1584562015-03-12 15:46:29 -07001325 } else {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001326 if (!android_log_is_loggable) {
1327 fprintf(stderr, "\n");
1328 }
1329 EXPECT_TRUE(android_log_is_loggable);
Mark Salyzyn504daa62016-04-14 15:31:56 -07001330 for(size_t k = 10; k; --k) {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001331 EXPECT_TRUE(__android_log_is_loggable(
1332 levels[i].level, tag, ANDROID_LOG_DEBUG));
1333 }
Mark Salyzync1584562015-03-12 15:46:29 -07001334 }
1335 property_set(key, "");
1336
1337 fprintf(stderr, "i=%zu j=%zu property_set(\"%s\",\"%s\")\r",
1338 i, j, key + base_offset, buf);
1339 property_set(key + base_offset, buf);
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001340 android_log_is_loggable = __android_log_is_loggable(
1341 levels[i].level, tag, ANDROID_LOG_DEBUG);
Mark Salyzync1584562015-03-12 15:46:29 -07001342 if ((levels[i].level < levels[j].level)
1343 || (levels[j].level == -1)
1344 || ((levels[i].level < ANDROID_LOG_DEBUG)
1345 && (levels[j].level == -2))) {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001346 if (android_log_is_loggable) {
1347 fprintf(stderr, "\n");
1348 }
1349 EXPECT_FALSE(android_log_is_loggable);
Mark Salyzyn504daa62016-04-14 15:31:56 -07001350 for(size_t k = 10; k; --k) {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001351 EXPECT_FALSE(__android_log_is_loggable(
1352 levels[i].level, tag, ANDROID_LOG_DEBUG));
1353 }
Mark Salyzync1584562015-03-12 15:46:29 -07001354 } else {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001355 if (!android_log_is_loggable) {
1356 fprintf(stderr, "\n");
1357 }
1358 EXPECT_TRUE(android_log_is_loggable);
Mark Salyzyn504daa62016-04-14 15:31:56 -07001359 for(size_t k = 10; k; --k) {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001360 EXPECT_TRUE(__android_log_is_loggable(
1361 levels[i].level, tag, ANDROID_LOG_DEBUG));
1362 }
Mark Salyzync1584562015-03-12 15:46:29 -07001363 }
1364 property_set(key + base_offset, "");
1365
1366 strcpy(key, log_namespace);
1367 key[sizeof(log_namespace) - 2] = '\0';
1368 fprintf(stderr, "i=%zu j=%zu property_set(\"%s\",\"%s\")\r",
1369 i, j, key, buf);
1370 property_set(key, buf);
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001371 android_log_is_loggable = __android_log_is_loggable(
1372 levels[i].level, tag, ANDROID_LOG_DEBUG);
Mark Salyzync1584562015-03-12 15:46:29 -07001373 if ((levels[i].level < levels[j].level)
1374 || (levels[j].level == -1)
1375 || ((levels[i].level < ANDROID_LOG_DEBUG)
1376 && (levels[j].level == -2))) {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001377 if (android_log_is_loggable) {
1378 fprintf(stderr, "\n");
1379 }
1380 EXPECT_FALSE(android_log_is_loggable);
Mark Salyzyn504daa62016-04-14 15:31:56 -07001381 for(size_t k = 10; k; --k) {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001382 EXPECT_FALSE(__android_log_is_loggable(
1383 levels[i].level, tag, ANDROID_LOG_DEBUG));
1384 }
Mark Salyzync1584562015-03-12 15:46:29 -07001385 } else {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001386 if (!android_log_is_loggable) {
1387 fprintf(stderr, "\n");
1388 }
1389 EXPECT_TRUE(android_log_is_loggable);
Mark Salyzyn504daa62016-04-14 15:31:56 -07001390 for(size_t k = 10; k; --k) {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001391 EXPECT_TRUE(__android_log_is_loggable(
1392 levels[i].level, tag, ANDROID_LOG_DEBUG));
1393 }
Mark Salyzync1584562015-03-12 15:46:29 -07001394 }
1395 property_set(key, "");
1396
1397 fprintf(stderr, "i=%zu j=%zu property_set(\"%s\",\"%s\")\r",
1398 i, j, key + base_offset, buf);
1399 property_set(key + base_offset, buf);
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001400 android_log_is_loggable = __android_log_is_loggable(
1401 levels[i].level, tag, ANDROID_LOG_DEBUG);
Mark Salyzync1584562015-03-12 15:46:29 -07001402 if ((levels[i].level < levels[j].level)
1403 || (levels[j].level == -1)
1404 || ((levels[i].level < ANDROID_LOG_DEBUG)
1405 && (levels[j].level == -2))) {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001406 if (android_log_is_loggable) {
1407 fprintf(stderr, "\n");
1408 }
1409 EXPECT_FALSE(android_log_is_loggable);
Mark Salyzyn504daa62016-04-14 15:31:56 -07001410 for(size_t k = 10; k; --k) {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001411 EXPECT_FALSE(__android_log_is_loggable(
1412 levels[i].level, tag, ANDROID_LOG_DEBUG));
1413 }
Mark Salyzync1584562015-03-12 15:46:29 -07001414 } else {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001415 if (!android_log_is_loggable) {
1416 fprintf(stderr, "\n");
1417 }
1418 EXPECT_TRUE(android_log_is_loggable);
Mark Salyzyn504daa62016-04-14 15:31:56 -07001419 for(size_t k = 10; k; --k) {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001420 EXPECT_TRUE(__android_log_is_loggable(
1421 levels[i].level, tag, ANDROID_LOG_DEBUG));
1422 }
Mark Salyzync1584562015-03-12 15:46:29 -07001423 }
1424 property_set(key + base_offset, "");
1425 }
1426 }
1427
1428 // All combinations of level and tag properties, but with global set to INFO
1429 strcpy(key, log_namespace);
1430 key[sizeof(log_namespace) - 2] = '\0';
1431 property_set(key, "I");
1432 snprintf(key, sizeof(key), "%s%s", log_namespace, tag);
1433 for(size_t i = 0; i < (sizeof(levels) / sizeof(levels[0])); ++i) {
1434 if (levels[i].level == -2) {
1435 continue;
1436 }
1437 for(size_t j = 0; j < (sizeof(levels) / sizeof(levels[0])); ++j) {
1438 char buf[2];
1439 buf[0] = levels[j].type;
1440 buf[1] = '\0';
1441
1442 fprintf(stderr, "i=%zu j=%zu property_set(\"%s\",\"%s\")\r",
1443 i, j, key, buf);
1444 property_set(key, buf);
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001445 bool android_log_is_loggable = __android_log_is_loggable(
1446 levels[i].level, tag, ANDROID_LOG_DEBUG);
Mark Salyzync1584562015-03-12 15:46:29 -07001447 if ((levels[i].level < levels[j].level)
1448 || (levels[j].level == -1)
1449 || ((levels[i].level < ANDROID_LOG_INFO) // Yes INFO
1450 && (levels[j].level == -2))) {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001451 if (android_log_is_loggable) {
1452 fprintf(stderr, "\n");
1453 }
1454 EXPECT_FALSE(android_log_is_loggable);
Mark Salyzyn504daa62016-04-14 15:31:56 -07001455 for(size_t k = 10; k; --k) {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001456 EXPECT_FALSE(__android_log_is_loggable(
1457 levels[i].level, tag, ANDROID_LOG_DEBUG));
1458 }
Mark Salyzync1584562015-03-12 15:46:29 -07001459 } else {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001460 if (!android_log_is_loggable) {
1461 fprintf(stderr, "\n");
1462 }
1463 EXPECT_TRUE(android_log_is_loggable);
Mark Salyzyn504daa62016-04-14 15:31:56 -07001464 for(size_t k = 10; k; --k) {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001465 EXPECT_TRUE(__android_log_is_loggable(
1466 levels[i].level, tag, ANDROID_LOG_DEBUG));
1467 }
Mark Salyzync1584562015-03-12 15:46:29 -07001468 }
1469 property_set(key, "");
1470
1471 fprintf(stderr, "i=%zu j=%zu property_set(\"%s\",\"%s\")\r",
1472 i, j, key + base_offset, buf);
1473 property_set(key + base_offset, buf);
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001474 android_log_is_loggable = __android_log_is_loggable(
1475 levels[i].level, tag, ANDROID_LOG_DEBUG);
Mark Salyzync1584562015-03-12 15:46:29 -07001476 if ((levels[i].level < levels[j].level)
1477 || (levels[j].level == -1)
1478 || ((levels[i].level < ANDROID_LOG_INFO) // Yes INFO
1479 && (levels[j].level == -2))) {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001480 if (android_log_is_loggable) {
1481 fprintf(stderr, "\n");
1482 }
1483 EXPECT_FALSE(android_log_is_loggable);
Mark Salyzyn504daa62016-04-14 15:31:56 -07001484 for(size_t k = 10; k; --k) {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001485 EXPECT_FALSE(__android_log_is_loggable(
1486 levels[i].level, tag, ANDROID_LOG_DEBUG));
1487 }
Mark Salyzync1584562015-03-12 15:46:29 -07001488 } else {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001489 if (!android_log_is_loggable) {
1490 fprintf(stderr, "\n");
1491 }
1492 EXPECT_TRUE(android_log_is_loggable);
Mark Salyzyn504daa62016-04-14 15:31:56 -07001493 for(size_t k = 10; k; --k) {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001494 EXPECT_TRUE(__android_log_is_loggable(
1495 levels[i].level, tag, ANDROID_LOG_DEBUG));
1496 }
Mark Salyzync1584562015-03-12 15:46:29 -07001497 }
1498 property_set(key + base_offset, "");
1499 }
1500 }
1501
1502 // reset parms
1503 snprintf(key, sizeof(key), "%s%s", log_namespace, tag);
1504 property_set(key, hold[0]);
1505 property_set(key + base_offset, hold[1]);
1506 strcpy(key, log_namespace);
1507 key[sizeof(log_namespace) - 2] = '\0';
1508 property_set(key, hold[2]);
1509 property_set(key + base_offset, hold[3]);
1510}
William Luh964428c2015-08-13 10:41:58 -07001511
William Luh964428c2015-08-13 10:41:58 -07001512TEST(liblog, android_errorWriteWithInfoLog__android_logger_list_read__typical) {
1513 const int TAG = 123456781;
1514 const char SUBTAG[] = "test-subtag";
1515 const int UID = -1;
1516 const int DATA_LEN = 200;
1517 struct logger_list *logger_list;
1518
1519 pid_t pid = getpid();
1520
1521 ASSERT_TRUE(NULL != (logger_list = android_logger_list_open(
1522 LOG_ID_EVENTS, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 1000, pid)));
1523
1524 ASSERT_LT(0, android_errorWriteWithInfoLog(
1525 TAG, SUBTAG, UID, max_payload_buf, DATA_LEN));
1526
1527 sleep(2);
1528
1529 int count = 0;
1530
1531 for (;;) {
1532 log_msg log_msg;
1533 if (android_logger_list_read(logger_list, &log_msg) <= 0) {
1534 break;
1535 }
1536
1537 char *eventData = log_msg.msg();
1538
1539 // Tag
1540 int tag = get4LE(eventData);
1541 eventData += 4;
1542
1543 if (tag != TAG) {
1544 continue;
1545 }
1546
1547 // List type
1548 ASSERT_EQ(EVENT_TYPE_LIST, eventData[0]);
1549 eventData++;
1550
1551 // Number of elements in list
1552 ASSERT_EQ(3, eventData[0]);
1553 eventData++;
1554
1555 // Element #1: string type for subtag
1556 ASSERT_EQ(EVENT_TYPE_STRING, eventData[0]);
1557 eventData++;
1558
1559 ASSERT_EQ((int) strlen(SUBTAG), get4LE(eventData));
1560 eventData +=4;
1561
1562 if (memcmp(SUBTAG, eventData, strlen(SUBTAG))) {
1563 continue;
1564 }
1565 eventData += strlen(SUBTAG);
1566
1567 // Element #2: int type for uid
1568 ASSERT_EQ(EVENT_TYPE_INT, eventData[0]);
1569 eventData++;
1570
1571 ASSERT_EQ(UID, get4LE(eventData));
1572 eventData += 4;
1573
1574 // Element #3: string type for data
1575 ASSERT_EQ(EVENT_TYPE_STRING, eventData[0]);
1576 eventData++;
1577
1578 ASSERT_EQ(DATA_LEN, get4LE(eventData));
1579 eventData += 4;
1580
1581 if (memcmp(max_payload_buf, eventData, DATA_LEN)) {
1582 continue;
1583 }
1584
1585 ++count;
1586 }
1587
1588 EXPECT_EQ(1, count);
1589
1590 android_logger_list_close(logger_list);
1591}
1592
1593TEST(liblog, android_errorWriteWithInfoLog__android_logger_list_read__data_too_large) {
1594 const int TAG = 123456782;
1595 const char SUBTAG[] = "test-subtag";
1596 const int UID = -1;
Mark Salyzynd9aee652016-02-25 09:02:09 -08001597 const int DATA_LEN = sizeof(max_payload_buf);
William Luh964428c2015-08-13 10:41:58 -07001598 struct logger_list *logger_list;
1599
1600 pid_t pid = getpid();
1601
1602 ASSERT_TRUE(NULL != (logger_list = android_logger_list_open(
1603 LOG_ID_EVENTS, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 1000, pid)));
1604
1605 ASSERT_LT(0, android_errorWriteWithInfoLog(
1606 TAG, SUBTAG, UID, max_payload_buf, DATA_LEN));
1607
1608 sleep(2);
1609
1610 int count = 0;
1611
1612 for (;;) {
1613 log_msg log_msg;
1614 if (android_logger_list_read(logger_list, &log_msg) <= 0) {
1615 break;
1616 }
1617
1618 char *eventData = log_msg.msg();
1619 char *original = eventData;
1620
1621 // Tag
1622 int tag = get4LE(eventData);
1623 eventData += 4;
1624
1625 if (tag != TAG) {
1626 continue;
1627 }
1628
1629 // List type
1630 ASSERT_EQ(EVENT_TYPE_LIST, eventData[0]);
1631 eventData++;
1632
1633 // Number of elements in list
1634 ASSERT_EQ(3, eventData[0]);
1635 eventData++;
1636
1637 // Element #1: string type for subtag
1638 ASSERT_EQ(EVENT_TYPE_STRING, eventData[0]);
1639 eventData++;
1640
1641 ASSERT_EQ((int) strlen(SUBTAG), get4LE(eventData));
1642 eventData +=4;
1643
1644 if (memcmp(SUBTAG, eventData, strlen(SUBTAG))) {
1645 continue;
1646 }
1647 eventData += strlen(SUBTAG);
1648
1649 // Element #2: int type for uid
1650 ASSERT_EQ(EVENT_TYPE_INT, eventData[0]);
1651 eventData++;
1652
1653 ASSERT_EQ(UID, get4LE(eventData));
1654 eventData += 4;
1655
1656 // Element #3: string type for data
1657 ASSERT_EQ(EVENT_TYPE_STRING, eventData[0]);
1658 eventData++;
1659
1660 size_t dataLen = get4LE(eventData);
1661 eventData += 4;
1662
1663 if (memcmp(max_payload_buf, eventData, dataLen)) {
1664 continue;
1665 }
1666 eventData += dataLen;
1667
Mark Salyzynd9aee652016-02-25 09:02:09 -08001668 // 4 bytes for the tag, and max_payload_buf should be truncated.
1669 ASSERT_LE(4 + 512, eventData - original); // worst expectations
1670 ASSERT_GT(4 + DATA_LEN, eventData - original); // must be truncated
William Luh964428c2015-08-13 10:41:58 -07001671
1672 ++count;
1673 }
1674
1675 EXPECT_EQ(1, count);
1676
1677 android_logger_list_close(logger_list);
1678}
1679
1680TEST(liblog, android_errorWriteWithInfoLog__android_logger_list_read__null_data) {
1681 const int TAG = 123456783;
1682 const char SUBTAG[] = "test-subtag";
1683 const int UID = -1;
1684 const int DATA_LEN = 200;
1685 struct logger_list *logger_list;
1686
1687 pid_t pid = getpid();
1688
1689 ASSERT_TRUE(NULL != (logger_list = android_logger_list_open(
1690 LOG_ID_EVENTS, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 1000, pid)));
1691
1692 ASSERT_GT(0, android_errorWriteWithInfoLog(
1693 TAG, SUBTAG, UID, NULL, DATA_LEN));
1694
1695 sleep(2);
1696
1697 int count = 0;
1698
1699 for (;;) {
1700 log_msg log_msg;
1701 if (android_logger_list_read(logger_list, &log_msg) <= 0) {
1702 break;
1703 }
1704
1705 char *eventData = log_msg.msg();
1706
1707 // Tag
1708 int tag = get4LE(eventData);
1709 eventData += 4;
1710
1711 if (tag == TAG) {
1712 // This tag should not have been written because the data was null
1713 count++;
1714 break;
1715 }
1716 }
1717
1718 EXPECT_EQ(0, count);
1719
1720 android_logger_list_close(logger_list);
1721}
1722
1723TEST(liblog, android_errorWriteWithInfoLog__android_logger_list_read__subtag_too_long) {
1724 const int TAG = 123456784;
1725 const char SUBTAG[] = "abcdefghijklmnopqrstuvwxyz now i know my abc";
1726 const int UID = -1;
1727 const int DATA_LEN = 200;
1728 struct logger_list *logger_list;
1729
1730 pid_t pid = getpid();
1731
1732 ASSERT_TRUE(NULL != (logger_list = android_logger_list_open(
1733 LOG_ID_EVENTS, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 1000, pid)));
1734
1735 ASSERT_LT(0, android_errorWriteWithInfoLog(
1736 TAG, SUBTAG, UID, max_payload_buf, DATA_LEN));
1737
1738 sleep(2);
1739
1740 int count = 0;
1741
1742 for (;;) {
1743 log_msg log_msg;
1744 if (android_logger_list_read(logger_list, &log_msg) <= 0) {
1745 break;
1746 }
1747
1748 char *eventData = log_msg.msg();
1749
1750 // Tag
1751 int tag = get4LE(eventData);
1752 eventData += 4;
1753
1754 if (tag != TAG) {
1755 continue;
1756 }
1757
1758 // List type
1759 ASSERT_EQ(EVENT_TYPE_LIST, eventData[0]);
1760 eventData++;
1761
1762 // Number of elements in list
1763 ASSERT_EQ(3, eventData[0]);
1764 eventData++;
1765
1766 // Element #1: string type for subtag
1767 ASSERT_EQ(EVENT_TYPE_STRING, eventData[0]);
1768 eventData++;
1769
1770 // The subtag is longer than 32 and should be truncated to that.
1771 ASSERT_EQ(32, get4LE(eventData));
1772 eventData +=4;
1773
1774 if (memcmp(SUBTAG, eventData, 32)) {
1775 continue;
1776 }
1777 eventData += 32;
1778
1779 // Element #2: int type for uid
1780 ASSERT_EQ(EVENT_TYPE_INT, eventData[0]);
1781 eventData++;
1782
1783 ASSERT_EQ(UID, get4LE(eventData));
1784 eventData += 4;
1785
1786 // Element #3: string type for data
1787 ASSERT_EQ(EVENT_TYPE_STRING, eventData[0]);
1788 eventData++;
1789
1790 ASSERT_EQ(DATA_LEN, get4LE(eventData));
1791 eventData += 4;
1792
1793 if (memcmp(max_payload_buf, eventData, DATA_LEN)) {
1794 continue;
1795 }
1796
1797 ++count;
1798 }
1799
1800 EXPECT_EQ(1, count);
1801
1802 android_logger_list_close(logger_list);
1803}
1804
1805TEST(liblog, android_errorWriteLog__android_logger_list_read__success) {
1806 const int TAG = 123456785;
1807 const char SUBTAG[] = "test-subtag";
1808 struct logger_list *logger_list;
1809
1810 pid_t pid = getpid();
1811
1812 ASSERT_TRUE(NULL != (logger_list = android_logger_list_open(
1813 LOG_ID_EVENTS, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 1000, pid)));
1814
1815 ASSERT_LT(0, android_errorWriteLog(TAG, SUBTAG));
1816
1817 sleep(2);
1818
1819 int count = 0;
1820
1821 for (;;) {
1822 log_msg log_msg;
1823 if (android_logger_list_read(logger_list, &log_msg) <= 0) {
1824 break;
1825 }
1826
1827 char *eventData = log_msg.msg();
1828
1829 // Tag
1830 int tag = get4LE(eventData);
1831 eventData += 4;
1832
1833 if (tag != TAG) {
1834 continue;
1835 }
1836
1837 // List type
1838 ASSERT_EQ(EVENT_TYPE_LIST, eventData[0]);
1839 eventData++;
1840
1841 // Number of elements in list
1842 ASSERT_EQ(3, eventData[0]);
1843 eventData++;
1844
1845 // Element #1: string type for subtag
1846 ASSERT_EQ(EVENT_TYPE_STRING, eventData[0]);
1847 eventData++;
1848
1849 ASSERT_EQ((int) strlen(SUBTAG), get4LE(eventData));
1850 eventData +=4;
1851
1852 if (memcmp(SUBTAG, eventData, strlen(SUBTAG))) {
1853 continue;
1854 }
1855 ++count;
1856 }
1857
1858 EXPECT_EQ(1, count);
1859
1860 android_logger_list_close(logger_list);
1861}
1862
1863TEST(liblog, android_errorWriteLog__android_logger_list_read__null_subtag) {
1864 const int TAG = 123456786;
1865 struct logger_list *logger_list;
1866
1867 pid_t pid = getpid();
1868
1869 ASSERT_TRUE(NULL != (logger_list = android_logger_list_open(
1870 LOG_ID_EVENTS, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 1000, pid)));
1871
1872 ASSERT_GT(0, android_errorWriteLog(TAG, NULL));
1873
1874 sleep(2);
1875
1876 int count = 0;
1877
1878 for (;;) {
1879 log_msg log_msg;
1880 if (android_logger_list_read(logger_list, &log_msg) <= 0) {
1881 break;
1882 }
1883
1884 char *eventData = log_msg.msg();
1885
1886 // Tag
1887 int tag = get4LE(eventData);
1888 eventData += 4;
1889
1890 if (tag == TAG) {
1891 // This tag should not have been written because the data was null
1892 count++;
1893 break;
1894 }
1895 }
1896
1897 EXPECT_EQ(0, count);
1898
1899 android_logger_list_close(logger_list);
1900}
Mark Salyzyn9dd65102016-02-17 16:08:13 -08001901
1902static int is_real_element(int type) {
1903 return ((type == EVENT_TYPE_INT) ||
1904 (type == EVENT_TYPE_LONG) ||
1905 (type == EVENT_TYPE_STRING) ||
1906 (type == EVENT_TYPE_FLOAT));
1907}
1908
1909int android_log_buffer_to_string(const char *msg, size_t len,
1910 char *strOut, size_t strOutLen) {
1911 android_log_context context = create_android_log_parser(msg, len);
1912 android_log_list_element elem;
1913 bool overflow = false;
1914 /* Reserve 1 byte for null terminator. */
1915 size_t origStrOutLen = strOutLen--;
1916
1917 if (!context) {
1918 return -EBADF;
1919 }
1920
1921 memset(&elem, 0, sizeof(elem));
1922
1923 size_t outCount;
1924
1925 do {
1926 elem = android_log_read_next(context);
1927 switch ((int)elem.type) {
1928 case EVENT_TYPE_LIST:
1929 if (strOutLen == 0) {
1930 overflow = true;
1931 } else {
1932 *strOut++ = '[';
1933 strOutLen--;
1934 }
1935 break;
1936
1937 case EVENT_TYPE_LIST_STOP:
1938 if (strOutLen == 0) {
1939 overflow = true;
1940 } else {
1941 *strOut++ = ']';
1942 strOutLen--;
1943 }
1944 break;
1945
1946 case EVENT_TYPE_INT:
1947 /*
1948 * snprintf also requires room for the null terminator, which
1949 * we don't care about but we have allocated enough room for
1950 * that
1951 */
1952 outCount = snprintf(strOut, strOutLen + 1,
1953 "%" PRId32, elem.data.int32);
1954 if (outCount <= strOutLen) {
1955 strOut += outCount;
1956 strOutLen -= outCount;
1957 } else {
1958 overflow = true;
1959 }
1960 break;
1961
1962 case EVENT_TYPE_LONG:
1963 /*
1964 * snprintf also requires room for the null terminator, which
1965 * we don't care about but we have allocated enough room for
1966 * that
1967 */
1968 outCount = snprintf(strOut, strOutLen + 1,
1969 "%" PRId64, elem.data.int64);
1970 if (outCount <= strOutLen) {
1971 strOut += outCount;
1972 strOutLen -= outCount;
1973 } else {
1974 overflow = true;
1975 }
1976 break;
1977
1978 case EVENT_TYPE_FLOAT:
1979 /*
1980 * snprintf also requires room for the null terminator, which
1981 * we don't care about but we have allocated enough room for
1982 * that
1983 */
1984 outCount = snprintf(strOut, strOutLen + 1, "%f", elem.data.float32);
1985 if (outCount <= strOutLen) {
1986 strOut += outCount;
1987 strOutLen -= outCount;
1988 } else {
1989 overflow = true;
1990 }
1991 break;
1992
1993 default:
1994 elem.complete = true;
1995 break;
1996
1997 case EVENT_TYPE_UNKNOWN:
1998#if 0 // Ideal purity in the test, we want to complain about UNKNOWN showing up
1999 if (elem.complete) {
2000 break;
2001 }
2002#endif
2003 elem.data.string = const_cast<char *>("<unknown>");
2004 elem.len = strlen(elem.data.string);
2005 /* FALLTHRU */
2006 case EVENT_TYPE_STRING:
2007 if (elem.len <= strOutLen) {
2008 memcpy(strOut, elem.data.string, elem.len);
2009 strOut += elem.len;
2010 strOutLen -= elem.len;
2011 } else if (strOutLen > 0) {
2012 /* copy what we can */
2013 memcpy(strOut, elem.data.string, strOutLen);
2014 strOut += strOutLen;
2015 strOutLen = 0;
2016 overflow = true;
2017 }
2018 break;
2019 }
2020
2021 if (elem.complete) {
2022 break;
2023 }
2024 /* Determine whether to put a comma or not. */
2025 if (!overflow && (is_real_element(elem.type) ||
2026 (elem.type == EVENT_TYPE_LIST_STOP))) {
2027 android_log_list_element next = android_log_peek_next(context);
2028 if (!next.complete && (is_real_element(next.type) ||
2029 (next.type == EVENT_TYPE_LIST))) {
2030 if (strOutLen == 0) {
2031 overflow = true;
2032 } else {
2033 *strOut++ = ',';
2034 strOutLen--;
2035 }
2036 }
2037 }
2038 } while ((elem.type != EVENT_TYPE_UNKNOWN) && !overflow && !elem.complete);
2039
2040 android_log_destroy(&context);
2041
2042 if (overflow) {
2043 if (strOutLen < origStrOutLen) {
2044 /* leave an indicator */
2045 *(strOut-1) = '!';
2046 } else {
2047 /* nothing was written at all */
2048 *strOut++ = '!';
2049 }
2050 }
2051 *strOut++ = '\0';
2052
2053 if ((elem.type == EVENT_TYPE_UNKNOWN) && !elem.complete) {
2054 fprintf(stderr, "Binary log entry conversion failed\n");
2055 return -EINVAL;
2056 }
2057
2058 return 0;
2059}
2060
2061static const char *event_test_int32(uint32_t tag, size_t &expected_len) {
2062 android_log_context ctx;
2063
2064 EXPECT_TRUE(NULL != (ctx = create_android_logger(tag)));
2065 if (!ctx) {
2066 return NULL;
2067 }
2068 EXPECT_LE(0, android_log_write_int32(ctx, 0x40302010));
2069 EXPECT_LE(0, android_log_write_list(ctx, LOG_ID_EVENTS));
2070 EXPECT_LE(0, android_log_destroy(&ctx));
2071 EXPECT_TRUE(NULL == ctx);
2072
2073 expected_len = sizeof(uint32_t) +
2074 sizeof(uint8_t) + sizeof(uint32_t);
2075
2076 return "1076895760";
2077}
2078
2079static const char *event_test_int64(uint32_t tag, size_t &expected_len) {
2080 android_log_context ctx;
2081
2082 EXPECT_TRUE(NULL != (ctx = create_android_logger(tag)));
2083 if (!ctx) {
2084 return NULL;
2085 }
2086 EXPECT_LE(0, android_log_write_int64(ctx, 0x8070605040302010));
2087 EXPECT_LE(0, android_log_write_list(ctx, LOG_ID_EVENTS));
2088 EXPECT_LE(0, android_log_destroy(&ctx));
2089 EXPECT_TRUE(NULL == ctx);
2090
2091 expected_len = sizeof(uint32_t) +
2092 sizeof(uint8_t) + sizeof(uint64_t);
2093
2094 return "-9191740941672636400";
2095}
2096
2097static const char *event_test_list_int64(uint32_t tag, size_t &expected_len) {
2098 android_log_context ctx;
2099
2100 EXPECT_TRUE(NULL != (ctx = create_android_logger(tag)));
2101 if (!ctx) {
2102 return NULL;
2103 }
2104 EXPECT_LE(0, android_log_write_list_begin(ctx));
2105 EXPECT_LE(0, android_log_write_int64(ctx, 0x8070605040302010));
2106 EXPECT_LE(0, android_log_write_list_end(ctx));
2107 EXPECT_LE(0, android_log_write_list(ctx, LOG_ID_EVENTS));
2108 EXPECT_LE(0, android_log_destroy(&ctx));
2109 EXPECT_TRUE(NULL == ctx);
2110
2111 expected_len = sizeof(uint32_t) +
2112 sizeof(uint8_t) + sizeof(uint8_t) +
2113 sizeof(uint8_t) + sizeof(uint64_t);
2114
2115 return "[-9191740941672636400]";
2116}
2117
2118static const char *event_test_simple_automagic_list(uint32_t tag, size_t &expected_len) {
2119 android_log_context ctx;
2120
2121 EXPECT_TRUE(NULL != (ctx = create_android_logger(tag)));
2122 if (!ctx) {
2123 return NULL;
2124 }
2125 // The convenience API where we allow a simple list to be
2126 // created without explicit begin or end calls.
2127 EXPECT_LE(0, android_log_write_int32(ctx, 0x40302010));
2128 EXPECT_LE(0, android_log_write_int64(ctx, 0x8070605040302010));
2129 EXPECT_LE(0, android_log_write_list(ctx, LOG_ID_EVENTS));
2130 EXPECT_LE(0, android_log_destroy(&ctx));
2131 EXPECT_TRUE(NULL == ctx);
2132
2133 expected_len = sizeof(uint32_t) +
2134 sizeof(uint8_t) + sizeof(uint8_t) +
2135 sizeof(uint8_t) + sizeof(uint32_t) +
2136 sizeof(uint8_t) + sizeof(uint64_t);
2137
2138 return "[1076895760,-9191740941672636400]";
2139}
2140
2141static const char *event_test_list_empty(uint32_t tag, size_t &expected_len) {
2142 android_log_context ctx;
2143
2144 EXPECT_TRUE(NULL != (ctx = create_android_logger(tag)));
2145 if (!ctx) {
2146 return NULL;
2147 }
2148 EXPECT_LE(0, android_log_write_list_begin(ctx));
2149 EXPECT_LE(0, android_log_write_list_end(ctx));
2150 EXPECT_LE(0, android_log_write_list(ctx, LOG_ID_EVENTS));
2151 EXPECT_LE(0, android_log_destroy(&ctx));
2152 EXPECT_TRUE(NULL == ctx);
2153
2154 expected_len = sizeof(uint32_t) +
2155 sizeof(uint8_t) + sizeof(uint8_t);
2156
2157 return "[]";
2158}
2159
2160static const char *event_test_complex_nested_list(uint32_t tag, size_t &expected_len) {
2161 android_log_context ctx;
2162
2163 EXPECT_TRUE(NULL != (ctx = create_android_logger(tag)));
2164 if (!ctx) {
2165 return NULL;
2166 }
2167
2168 EXPECT_LE(0, android_log_write_list_begin(ctx)); // [
2169 EXPECT_LE(0, android_log_write_int32(ctx, 0x01020304));
2170 EXPECT_LE(0, android_log_write_int64(ctx, 0x0102030405060708));
2171 EXPECT_LE(0, android_log_write_string8(ctx, "Hello World"));
2172 EXPECT_LE(0, android_log_write_list_begin(ctx)); // [
2173 EXPECT_LE(0, android_log_write_int32(ctx, 1));
2174 EXPECT_LE(0, android_log_write_int32(ctx, 2));
2175 EXPECT_LE(0, android_log_write_int32(ctx, 3));
2176 EXPECT_LE(0, android_log_write_int32(ctx, 4));
2177 EXPECT_LE(0, android_log_write_list_end(ctx)); // ]
2178 EXPECT_LE(0, android_log_write_float32(ctx, 1.0102030405060708));
2179 EXPECT_LE(0, android_log_write_list_end(ctx)); // ]
2180
2181 //
2182 // This one checks for the automagic list creation because a list
2183 // begin and end was missing for it! This is actually an <oops> corner
2184 // case, and not the behavior we morally support. The automagic API is to
2185 // allow for a simple case of a series of objects in a single list. e.g.
2186 // int32,int32,int32,string -> [int32,int32,int32,string]
2187 //
2188 EXPECT_LE(0, android_log_write_string8(ctx, "dlroW olleH"));
2189
2190 EXPECT_LE(0, android_log_write_list(ctx, LOG_ID_EVENTS));
2191 EXPECT_LE(0, android_log_destroy(&ctx));
2192 EXPECT_TRUE(NULL == ctx);
2193
2194 expected_len = sizeof(uint32_t) +
2195 sizeof(uint8_t) + sizeof(uint8_t) +
2196 sizeof(uint8_t) + sizeof(uint8_t) +
2197 sizeof(uint8_t) + sizeof(uint32_t) +
2198 sizeof(uint8_t) + sizeof(uint64_t) +
2199 sizeof(uint8_t) + sizeof(uint32_t) +
2200 sizeof("Hello World") - 1 +
2201 sizeof(uint8_t) + sizeof(uint8_t) +
2202 4 * (sizeof(uint8_t) + sizeof(uint32_t)) +
2203 sizeof(uint8_t) + sizeof(uint32_t) +
2204 sizeof(uint8_t) + sizeof(uint32_t) +
2205 sizeof("dlroW olleH") - 1;
2206
2207 return "[[16909060,72623859790382856,Hello World,[1,2,3,4],1.010203],dlroW olleH]";
2208}
2209
2210static const char *event_test_7_level_prefix(uint32_t tag, size_t &expected_len) {
2211 android_log_context ctx;
2212
2213 EXPECT_TRUE(NULL != (ctx = create_android_logger(tag)));
2214 if (!ctx) {
2215 return NULL;
2216 }
2217 EXPECT_LE(0, android_log_write_list_begin(ctx));
2218 EXPECT_LE(0, android_log_write_list_begin(ctx));
2219 EXPECT_LE(0, android_log_write_list_begin(ctx));
2220 EXPECT_LE(0, android_log_write_list_begin(ctx));
2221 EXPECT_LE(0, android_log_write_list_begin(ctx));
2222 EXPECT_LE(0, android_log_write_list_begin(ctx));
2223 EXPECT_LE(0, android_log_write_list_begin(ctx));
2224 EXPECT_LE(0, android_log_write_int32(ctx, 1));
2225 EXPECT_LE(0, android_log_write_list_end(ctx));
2226 EXPECT_LE(0, android_log_write_int32(ctx, 2));
2227 EXPECT_LE(0, android_log_write_list_end(ctx));
2228 EXPECT_LE(0, android_log_write_int32(ctx, 3));
2229 EXPECT_LE(0, android_log_write_list_end(ctx));
2230 EXPECT_LE(0, android_log_write_int32(ctx, 4));
2231 EXPECT_LE(0, android_log_write_list_end(ctx));
2232 EXPECT_LE(0, android_log_write_int32(ctx, 5));
2233 EXPECT_LE(0, android_log_write_list_end(ctx));
2234 EXPECT_LE(0, android_log_write_int32(ctx, 6));
2235 EXPECT_LE(0, android_log_write_list_end(ctx));
2236 EXPECT_LE(0, android_log_write_int32(ctx, 7));
2237 EXPECT_LE(0, android_log_write_list_end(ctx));
2238 EXPECT_LE(0, android_log_write_list(ctx, LOG_ID_EVENTS));
2239 EXPECT_LE(0, android_log_destroy(&ctx));
2240 EXPECT_TRUE(NULL == ctx);
2241
2242 expected_len = sizeof(uint32_t) + 7 *
2243 (sizeof(uint8_t) + sizeof(uint8_t) + sizeof(uint8_t) + sizeof(uint32_t));
2244
2245 return "[[[[[[[1],2],3],4],5],6],7]";
2246}
2247
2248static const char *event_test_7_level_suffix(uint32_t tag, size_t &expected_len) {
2249 android_log_context ctx;
2250
2251 EXPECT_TRUE(NULL != (ctx = create_android_logger(tag)));
2252 if (!ctx) {
2253 return NULL;
2254 }
2255 EXPECT_LE(0, android_log_write_list_begin(ctx));
2256 EXPECT_LE(0, android_log_write_int32(ctx, 1));
2257 EXPECT_LE(0, android_log_write_list_begin(ctx));
2258 EXPECT_LE(0, android_log_write_int32(ctx, 2));
2259 EXPECT_LE(0, android_log_write_list_begin(ctx));
2260 EXPECT_LE(0, android_log_write_int32(ctx, 3));
2261 EXPECT_LE(0, android_log_write_list_begin(ctx));
2262 EXPECT_LE(0, android_log_write_int32(ctx, 4));
2263 EXPECT_LE(0, android_log_write_list_begin(ctx));
2264 EXPECT_LE(0, android_log_write_int32(ctx, 5));
2265 EXPECT_LE(0, android_log_write_list_begin(ctx));
2266 EXPECT_LE(0, android_log_write_int32(ctx, 6));
2267 EXPECT_LE(0, android_log_write_list_end(ctx));
2268 EXPECT_LE(0, android_log_write_list_end(ctx));
2269 EXPECT_LE(0, android_log_write_list_end(ctx));
2270 EXPECT_LE(0, android_log_write_list_end(ctx));
2271 EXPECT_LE(0, android_log_write_list_end(ctx));
2272 EXPECT_LE(0, android_log_write_list_end(ctx));
2273 EXPECT_LE(0, android_log_write_list(ctx, LOG_ID_EVENTS));
2274 EXPECT_LE(0, android_log_destroy(&ctx));
2275 EXPECT_TRUE(NULL == ctx);
2276
2277 expected_len = sizeof(uint32_t) + 6 *
2278 (sizeof(uint8_t) + sizeof(uint8_t) + sizeof(uint8_t) + sizeof(uint32_t));
2279
2280 return "[1,[2,[3,[4,[5,[6]]]]]]";
2281}
2282
Mark Salyzynd9aee652016-02-25 09:02:09 -08002283static const char *event_test_android_log_error_write(uint32_t tag, size_t &expected_len) {
2284 EXPECT_LE(0, __android_log_error_write(tag, "Hello World", 42, "dlroW olleH", 11));
2285
2286 expected_len = sizeof(uint32_t) +
2287 sizeof(uint8_t) + sizeof(uint8_t) +
2288 sizeof(uint8_t) + sizeof(uint32_t) + sizeof("Hello World") - 1 +
2289 sizeof(uint8_t) + sizeof(uint32_t) +
2290 sizeof(uint8_t) + sizeof(uint32_t) + sizeof("dlroW olleH") - 1;
2291
2292 return "[Hello World,42,dlroW olleH]";
2293}
2294
2295static const char *event_test_android_log_error_write_null(uint32_t tag, size_t &expected_len) {
2296 EXPECT_LE(0, __android_log_error_write(tag, "Hello World", 42, NULL, 0));
2297
2298 expected_len = sizeof(uint32_t) +
2299 sizeof(uint8_t) + sizeof(uint8_t) +
2300 sizeof(uint8_t) + sizeof(uint32_t) + sizeof("Hello World") - 1 +
2301 sizeof(uint8_t) + sizeof(uint32_t) +
2302 sizeof(uint8_t) + sizeof(uint32_t) + sizeof("") - 1;
2303
2304 return "[Hello World,42,]";
2305}
2306
Mark Salyzyn9dd65102016-02-17 16:08:13 -08002307// make sure all user buffers are flushed
2308static void print_barrier() {
2309 std::cout.flush();
2310 fflush(stdout);
2311 std::cerr.flush();
2312 fflush(stderr); // everything else is paranoia ...
2313}
2314
2315static void create_android_logger(const char *(*fn)(uint32_t tag, size_t &expected_len)) {
2316 struct logger_list *logger_list;
2317
2318 pid_t pid = getpid();
2319
2320 ASSERT_TRUE(NULL != (logger_list = android_logger_list_open(
2321 LOG_ID_EVENTS, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 1000, pid)));
2322
2323 log_time ts(android_log_clockid());
2324
2325 size_t expected_len;
2326 const char *expected_string = (*fn)(1005, expected_len);
2327
2328 if (!expected_string) {
2329 android_logger_list_close(logger_list);
2330 return;
2331 }
2332
2333 usleep(1000000);
2334
2335 int count = 0;
2336
2337 for (;;) {
2338 log_msg log_msg;
2339 if (android_logger_list_read(logger_list, &log_msg) <= 0) {
2340 break;
2341 }
2342
2343 ASSERT_EQ(log_msg.entry.pid, pid);
2344
2345 if ((log_msg.entry.sec < (ts.tv_sec - 1))
2346 || ((ts.tv_sec + 1) < log_msg.entry.sec)
2347 || ((size_t)log_msg.entry.len != expected_len)
2348 || (log_msg.id() != LOG_ID_EVENTS)) {
2349 continue;
2350 }
2351
2352 char *eventData = log_msg.msg();
2353
2354 ++count;
2355
2356 AndroidLogFormat *logformat = android_log_format_new();
2357 EXPECT_TRUE(NULL != logformat);
2358 AndroidLogEntry entry;
2359 char msgBuf[1024];
2360 int processBinaryLogBuffer = android_log_processBinaryLogBuffer(
2361 &log_msg.entry_v1, &entry, NULL, msgBuf, sizeof(msgBuf));
2362 EXPECT_EQ(0, processBinaryLogBuffer);
2363 if (processBinaryLogBuffer == 0) {
2364 print_barrier();
2365 int printLogLine = android_log_printLogLine(
2366 logformat, fileno(stderr), &entry);
2367 print_barrier();
2368 EXPECT_EQ(20 + (int)strlen(expected_string), printLogLine);
2369 }
2370 android_log_format_free(logformat);
2371
2372 // test buffer reading API
2373 snprintf(msgBuf, sizeof(msgBuf), "I/[%d]", get4LE(eventData));
2374 print_barrier();
2375 fprintf(stderr, "%-10s(%5u): ", msgBuf, pid);
2376 memset(msgBuf, 0, sizeof(msgBuf));
2377 int buffer_to_string = android_log_buffer_to_string(
2378 eventData + sizeof(uint32_t),
2379 log_msg.entry.len - sizeof(uint32_t),
2380 msgBuf, sizeof(msgBuf));
2381 fprintf(stderr, "%s\n", msgBuf);
2382 print_barrier();
2383 EXPECT_EQ(0, buffer_to_string);
2384 EXPECT_EQ(strlen(expected_string), strlen(msgBuf));
2385 EXPECT_EQ(0, strcmp(expected_string, msgBuf));
2386 }
2387
2388 EXPECT_EQ(1, count);
2389
2390 android_logger_list_close(logger_list);
2391}
2392
2393TEST(liblog, create_android_logger_int32) {
2394 create_android_logger(event_test_int32);
2395}
2396
2397TEST(liblog, create_android_logger_int64) {
2398 create_android_logger(event_test_int64);
2399}
2400
2401TEST(liblog, create_android_logger_list_int64) {
2402 create_android_logger(event_test_list_int64);
2403}
2404
2405TEST(liblog, create_android_logger_simple_automagic_list) {
2406 create_android_logger(event_test_simple_automagic_list);
2407}
2408
2409TEST(liblog, create_android_logger_list_empty) {
2410 create_android_logger(event_test_list_empty);
2411}
2412
2413TEST(liblog, create_android_logger_complex_nested_list) {
2414 create_android_logger(event_test_complex_nested_list);
2415}
2416
2417TEST(liblog, create_android_logger_7_level_prefix) {
2418 create_android_logger(event_test_7_level_prefix);
2419}
2420
2421TEST(liblog, create_android_logger_7_level_suffix) {
2422 create_android_logger(event_test_7_level_suffix);
2423}
2424
Mark Salyzynd9aee652016-02-25 09:02:09 -08002425TEST(liblog, create_android_logger_android_log_error_write) {
2426 create_android_logger(event_test_android_log_error_write);
2427}
2428
2429TEST(liblog, create_android_logger_android_log_error_write_null) {
2430 create_android_logger(event_test_android_log_error_write_null);
2431}
2432
Mark Salyzyn9dd65102016-02-17 16:08:13 -08002433TEST(liblog, create_android_logger_overflow) {
2434 android_log_context ctx;
2435
2436 EXPECT_TRUE(NULL != (ctx = create_android_logger(1005)));
2437 if (ctx) {
2438 for (size_t i = 0; i < ANDROID_MAX_LIST_NEST_DEPTH; ++i) {
2439 EXPECT_LE(0, android_log_write_list_begin(ctx));
2440 }
2441 EXPECT_GT(0, android_log_write_list_begin(ctx));
2442 /* One more for good measure, must be permanently unhappy */
2443 EXPECT_GT(0, android_log_write_list_begin(ctx));
2444 EXPECT_LE(0, android_log_destroy(&ctx));
2445 EXPECT_TRUE(NULL == ctx);
2446 }
2447
2448 ASSERT_TRUE(NULL != (ctx = create_android_logger(1005)));
2449 for (size_t i = 0; i < ANDROID_MAX_LIST_NEST_DEPTH; ++i) {
2450 EXPECT_LE(0, android_log_write_list_begin(ctx));
2451 EXPECT_LE(0, android_log_write_int32(ctx, i));
2452 }
2453 EXPECT_GT(0, android_log_write_list_begin(ctx));
2454 /* One more for good measure, must be permanently unhappy */
2455 EXPECT_GT(0, android_log_write_list_begin(ctx));
2456 EXPECT_LE(0, android_log_destroy(&ctx));
2457 ASSERT_TRUE(NULL == ctx);
2458}
Mark Salyzyn10bdf612016-03-10 09:50:08 -08002459
2460static const char __pmsg_file[] =
2461 "/data/william-shakespeare/MuchAdoAboutNothing.txt";
2462
2463TEST(liblog, __android_log_pmsg_file_write) {
2464 EXPECT_LT(0, __android_log_pmsg_file_write(
2465 LOG_ID_CRASH, ANDROID_LOG_VERBOSE,
2466 __pmsg_file, max_payload_buf, sizeof(max_payload_buf)));
Mark Salyzyn2b8157d2016-03-14 14:15:50 -07002467 fprintf(stderr, "Reboot, ensure file %s matches\n"
2468 "with liblog.__android_log_msg_file_read test\n",
2469 __pmsg_file);
2470}
2471
2472ssize_t __pmsg_fn(log_id_t logId, char prio, const char *filename,
2473 const char *buf, size_t len, void *arg) {
2474 EXPECT_TRUE(NULL == arg);
2475 EXPECT_EQ(LOG_ID_CRASH, logId);
2476 EXPECT_EQ(ANDROID_LOG_VERBOSE, prio);
2477 EXPECT_FALSE(NULL == strstr(__pmsg_file, filename));
2478 EXPECT_EQ(len, sizeof(max_payload_buf));
2479 EXPECT_EQ(0, strcmp(max_payload_buf, buf));
2480
2481 ++signaled;
2482 if ((len != sizeof(max_payload_buf)) ||
2483 strcmp(max_payload_buf, buf)) {
2484 fprintf(stderr, "comparison fails on content \"%s\"\n", buf);
2485 }
2486 return !arg ||
2487 (LOG_ID_CRASH != logId) ||
2488 (ANDROID_LOG_VERBOSE != prio) ||
2489 !strstr(__pmsg_file, filename) ||
2490 (len != sizeof(max_payload_buf)) ||
2491 !!strcmp(max_payload_buf, buf) ? -ENOEXEC : 1;
2492}
2493
2494TEST(liblog, __android_log_pmsg_file_read) {
2495 signaled = 0;
2496
2497 ssize_t ret = __android_log_pmsg_file_read(
2498 LOG_ID_CRASH, ANDROID_LOG_VERBOSE,
2499 __pmsg_file, __pmsg_fn, NULL);
2500
2501 if (ret == -ENOENT) {
2502 fprintf(stderr,
2503 "No pre-boot results of liblog.__android_log_mesg_file_write to "
2504 "compare with,\n"
2505 "false positive test result.\n");
2506 return;
2507 }
2508
2509 EXPECT_LT(0, ret);
2510 EXPECT_EQ(1U, signaled);
Mark Salyzyn10bdf612016-03-10 09:50:08 -08002511}