blob: df2c76603707cab7240bc7c490e6391cd674d8cf [file] [log] [blame]
Mark Salyzyn819c58a2013-11-22 12:39:43 -08001/*
Mark Salyzynbd1ad042016-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 Salyzyn50af7f82016-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
Mark Salyzyn66368722016-02-11 10:10:57 -0800177static void bswrite_test(const char *message) {
Mark Salyzyn7cc80132016-01-20 13:52:46 -0800178 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
Mark Salyzyn7cc80132016-01-20 13:52:46 -0800185 log_time ts(android_log_clockid());
186
Mark Salyzyn66368722016-02-11 10:10:57 -0800187 ASSERT_LT(0, __android_log_bswrite(0, message));
188 size_t num_lines = 1, size = 0, length = 0, total = 0;
189 const char *cp = message;
190 while (*cp) {
191 if (*cp == '\n') {
192 if (cp[1]) {
193 ++num_lines;
194 }
195 } else {
196 ++size;
197 }
198 ++cp;
199 ++total;
200 ++length;
201 if ((LOGGER_ENTRY_MAX_PAYLOAD - 4 - 1 - 4) <= length) {
202 break;
203 }
204 }
205 while (*cp) {
206 ++cp;
207 ++total;
208 }
Mark Salyzyn7cc80132016-01-20 13:52:46 -0800209 usleep(1000000);
210
211 int count = 0;
212
213 for (;;) {
214 log_msg log_msg;
215 if (android_logger_list_read(logger_list, &log_msg) <= 0) {
216 break;
217 }
218
219 ASSERT_EQ(log_msg.entry.pid, pid);
220
221 if ((log_msg.entry.sec < (ts.tv_sec - 1))
222 || ((ts.tv_sec + 1) < log_msg.entry.sec)
Mark Salyzyn66368722016-02-11 10:10:57 -0800223 || ((size_t)log_msg.entry.len != (4 + 1 + 4 + length))
Mark Salyzyn7cc80132016-01-20 13:52:46 -0800224 || (log_msg.id() != LOG_ID_EVENTS)) {
225 continue;
226 }
227
228 char *eventData = log_msg.msg();
229
230 if (eventData[4] != EVENT_TYPE_STRING) {
231 continue;
232 }
233
Mark Salyzyn66368722016-02-11 10:10:57 -0800234 size_t len = get4LE(eventData + 4 + 1);
235 if (len == total) {
Mark Salyzyn7cc80132016-01-20 13:52:46 -0800236 ++count;
237
238 AndroidLogFormat *logformat = android_log_format_new();
239 EXPECT_TRUE(NULL != logformat);
240 AndroidLogEntry entry;
241 char msgBuf[1024];
Mark Salyzyn66368722016-02-11 10:10:57 -0800242 int processBinaryLogBuffer = android_log_processBinaryLogBuffer(
243 &log_msg.entry_v1, &entry, NULL, msgBuf, sizeof(msgBuf));
244 EXPECT_EQ((length == total) ? 0 : -1, processBinaryLogBuffer);
245 if (processBinaryLogBuffer == 0) {
246 fflush(stderr);
247 EXPECT_EQ((int)((20 * num_lines) + size),
248 android_log_printLogLine(logformat, fileno(stderr), &entry));
249 }
Mark Salyzyn7cc80132016-01-20 13:52:46 -0800250 android_log_format_free(logformat);
251 }
252 }
253
254 EXPECT_EQ(1, count);
255
256 android_logger_list_close(logger_list);
257}
258
Mark Salyzyn66368722016-02-11 10:10:57 -0800259TEST(liblog, __android_log_bswrite_and_print) {
260 bswrite_test("Hello World");
Mark Salyzyn7cc80132016-01-20 13:52:46 -0800261}
262
Mark Salyzyn66368722016-02-11 10:10:57 -0800263TEST(liblog, __android_log_bswrite_and_print__empty_string) {
264 bswrite_test("");
Mark Salyzyn3f941222016-02-10 07:26:43 -0800265}
266
Mark Salyzyn66368722016-02-11 10:10:57 -0800267TEST(liblog, __android_log_bswrite_and_print__newline_prefix) {
268 bswrite_test("\nHello World\n");
269}
270
271TEST(liblog, __android_log_bswrite_and_print__newline_space_prefix) {
272 bswrite_test("\n Hello World \n");
273}
274
275TEST(liblog, __android_log_bswrite_and_print__multiple_newline) {
276 bswrite_test("one\ntwo\nthree\nfour\nfive\nsix\nseven\neight\nnine\nten");
277}
278
279static void buf_write_test(const char *message) {
Mark Salyzyn3f941222016-02-10 07:26:43 -0800280 struct logger_list *logger_list;
281
282 pid_t pid = getpid();
283
284 ASSERT_TRUE(NULL != (logger_list = android_logger_list_open(
285 LOG_ID_MAIN, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 1000, pid)));
286
287 static const char tag[] = "TEST__android_log_buf_write";
Mark Salyzyn3f941222016-02-10 07:26:43 -0800288 log_time ts(android_log_clockid());
289
290 EXPECT_LT(0, __android_log_buf_write(LOG_ID_MAIN, ANDROID_LOG_INFO,
Mark Salyzyn66368722016-02-11 10:10:57 -0800291 tag, message));
292 size_t num_lines = 1, size = 0, length = 0;
293 const char *cp = message;
294 while (*cp) {
295 if (*cp == '\n') {
296 if (cp[1]) {
297 ++num_lines;
298 }
299 } else {
300 ++size;
301 }
302 ++length;
303 if ((LOGGER_ENTRY_MAX_PAYLOAD - 2 - sizeof(tag)) <= length) {
304 break;
305 }
306 ++cp;
307 }
Mark Salyzyn3f941222016-02-10 07:26:43 -0800308 usleep(1000000);
309
310 int count = 0;
311
312 for (;;) {
313 log_msg log_msg;
314 if (android_logger_list_read(logger_list, &log_msg) <= 0) {
315 break;
316 }
317
318 ASSERT_EQ(log_msg.entry.pid, pid);
319
320 if ((log_msg.entry.sec < (ts.tv_sec - 1))
321 || ((ts.tv_sec + 1) < log_msg.entry.sec)
Mark Salyzyn66368722016-02-11 10:10:57 -0800322 || ((size_t)log_msg.entry.len != (sizeof(tag) + length + 2))
Mark Salyzyn3f941222016-02-10 07:26:43 -0800323 || (log_msg.id() != LOG_ID_MAIN)) {
324 continue;
325 }
326
327 ++count;
328
329 AndroidLogFormat *logformat = android_log_format_new();
330 EXPECT_TRUE(NULL != logformat);
331 AndroidLogEntry entry;
Mark Salyzyn66368722016-02-11 10:10:57 -0800332 int processLogBuffer = android_log_processLogBuffer(&log_msg.entry_v1,
333 &entry);
334 EXPECT_EQ(0, processLogBuffer);
335 if (processLogBuffer == 0) {
336 fflush(stderr);
337 EXPECT_EQ((int)(((11 + sizeof(tag)) * num_lines) + size),
338 android_log_printLogLine(logformat, fileno(stderr), &entry));
339 }
Mark Salyzyn3f941222016-02-10 07:26:43 -0800340 android_log_format_free(logformat);
341 }
342
343 EXPECT_EQ(1, count);
344
345 android_logger_list_close(logger_list);
346}
347
Mark Salyzyn66368722016-02-11 10:10:57 -0800348TEST(liblog, __android_log_buf_write_and_print__empty) {
349 buf_write_test("");
350}
351
352TEST(liblog, __android_log_buf_write_and_print__newline_prefix) {
353 buf_write_test("\nHello World\n");
354}
355
356TEST(liblog, __android_log_buf_write_and_print__newline_space_prefix) {
357 buf_write_test("\n Hello World \n");
358}
359
Mark Salyzynffbd86f2015-12-04 10:59:45 -0800360TEST(liblog, __security) {
361 static const char persist_key[] = "persist.logd.security";
362 static const char readonly_key[] = "ro.device_owner";
363 static const char nothing_val[] = "_NOTHING_TO_SEE_HERE_";
364 char persist[PROP_VALUE_MAX];
365 char readonly[PROP_VALUE_MAX];
366
367 property_get(persist_key, persist, "");
368 property_get(readonly_key, readonly, nothing_val);
369
370 if (!strcmp(readonly, nothing_val)) {
371 EXPECT_FALSE(__android_log_security());
372 fprintf(stderr, "Warning, setting ro.device_owner to a domain\n");
373 property_set(readonly_key, "com.google.android.SecOps.DeviceOwner");
374 } else if (!strcasecmp(readonly, "false") || !readonly[0]) {
375 EXPECT_FALSE(__android_log_security());
376 return;
377 }
378
379 if (!strcasecmp(persist, "true")) {
380 EXPECT_TRUE(__android_log_security());
381 } else {
382 EXPECT_FALSE(__android_log_security());
383 }
384 property_set(persist_key, "TRUE");
385 EXPECT_TRUE(__android_log_security());
386 property_set(persist_key, "FALSE");
387 EXPECT_FALSE(__android_log_security());
388 property_set(persist_key, "true");
389 EXPECT_TRUE(__android_log_security());
390 property_set(persist_key, "false");
391 EXPECT_FALSE(__android_log_security());
392 property_set(persist_key, "");
393 EXPECT_FALSE(__android_log_security());
394 property_set(persist_key, persist);
395}
396
Mark Salyzyn083b0372015-12-04 10:59:45 -0800397TEST(liblog, __security_buffer) {
398 struct logger_list *logger_list;
399 android_event_long_t buffer;
400
401 static const char persist_key[] = "persist.logd.security";
402 char persist[PROP_VALUE_MAX];
403 bool set_persist = false;
404 bool allow_security = false;
405
406 if (__android_log_security()) {
407 allow_security = true;
408 } else {
409 property_get(persist_key, persist, "");
410 if (strcasecmp(persist, "true")) {
411 property_set(persist_key, "TRUE");
412 if (__android_log_security()) {
413 allow_security = true;
414 set_persist = true;
415 } else {
416 property_set(persist_key, persist);
417 }
418 }
419 }
420
421 if (!allow_security) {
422 fprintf(stderr, "WARNING: "
423 "security buffer disabled, bypassing end-to-end test\n");
424
425 log_time ts(CLOCK_MONOTONIC);
426
427 buffer.type = EVENT_TYPE_LONG;
428 buffer.data = *(static_cast<uint64_t *>((void *)&ts));
429
430 // expect failure!
431 ASSERT_GE(0, __android_log_security_bwrite(0, &buffer, sizeof(buffer)));
432
433 return;
434 }
435
Mark Salyzyn8fa88962016-01-26 14:32:35 -0800436 /* Matches clientHasLogCredentials() in logd */
437 uid_t uid = getuid();
438 gid_t gid = getgid();
439 bool clientHasLogCredentials = true;
440 if ((uid != AID_SYSTEM) && (uid != AID_ROOT) && (uid != AID_LOG)
441 && (gid != AID_SYSTEM) && (gid != AID_ROOT) && (gid != AID_LOG)) {
442 uid_t euid = geteuid();
443 if ((euid != AID_SYSTEM) && (euid != AID_ROOT) && (euid != AID_LOG)) {
444 gid_t egid = getegid();
445 if ((egid != AID_SYSTEM) && (egid != AID_ROOT) && (egid != AID_LOG)) {
446 int num_groups = getgroups(0, NULL);
447 if (num_groups > 0) {
448 gid_t groups[num_groups];
449 num_groups = getgroups(num_groups, groups);
450 while (num_groups > 0) {
451 if (groups[num_groups - 1] == AID_LOG) {
452 break;
453 }
454 --num_groups;
455 }
456 }
457 if (num_groups <= 0) {
458 clientHasLogCredentials = false;
459 }
460 }
461 }
462 }
463 if (!clientHasLogCredentials) {
464 fprintf(stderr, "WARNING: "
465 "not in system context, bypassing end-to-end test\n");
466
467 log_time ts(CLOCK_MONOTONIC);
468
469 buffer.type = EVENT_TYPE_LONG;
470 buffer.data = *(static_cast<uint64_t *>((void *)&ts));
471
472 // expect failure!
473 ASSERT_GE(0, __android_log_security_bwrite(0, &buffer, sizeof(buffer)));
474
475 return;
476 }
477
Mark Salyzyn083b0372015-12-04 10:59:45 -0800478 pid_t pid = getpid();
479
480 ASSERT_TRUE(NULL != (logger_list = android_logger_list_open(
481 LOG_ID_SECURITY, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK,
482 1000, pid)));
483
484 log_time ts(CLOCK_MONOTONIC);
485
486 buffer.type = EVENT_TYPE_LONG;
487 buffer.data = *(static_cast<uint64_t *>((void *)&ts));
488
489 ASSERT_LT(0, __android_log_security_bwrite(0, &buffer, sizeof(buffer)));
490 usleep(1000000);
491
492 int count = 0;
493
494 for (;;) {
495 log_msg log_msg;
496 if (android_logger_list_read(logger_list, &log_msg) <= 0) {
497 break;
498 }
499
500 ASSERT_EQ(log_msg.entry.pid, pid);
501
502 if ((log_msg.entry.len != (4 + 1 + 8))
503 || (log_msg.id() != LOG_ID_SECURITY)) {
504 continue;
505 }
506
507 char *eventData = log_msg.msg();
508
509 if (eventData[4] != EVENT_TYPE_LONG) {
510 continue;
511 }
512
513 log_time tx(eventData + 4 + 1);
514 if (ts == tx) {
515 ++count;
516 }
517 }
518
519 if (set_persist) {
520 property_set(persist_key, persist);
521 }
522
523 android_logger_list_close(logger_list);
524
Mark Salyzyn8fa88962016-01-26 14:32:35 -0800525 bool clientHasSecurityCredentials = (uid == AID_SYSTEM) || (gid == AID_SYSTEM);
526 if (!clientHasSecurityCredentials) {
527 fprintf(stderr, "WARNING: "
528 "not system, content submitted but can not check end-to-end\n");
529 }
530 EXPECT_EQ(clientHasSecurityCredentials ? 1 : 0, count);
Mark Salyzyn083b0372015-12-04 10:59:45 -0800531
532}
533
Mark Salyzyncef098e2014-01-09 09:02:55 -0800534static unsigned signaled;
Mark Salyzyn50af7f82016-03-10 15:25:14 -0800535static log_time signal_time;
Mark Salyzyncef098e2014-01-09 09:02:55 -0800536
Mark Salyzyn50af7f82016-03-10 15:25:14 -0800537/*
538 * Strictly, we are not allowed to log messages in a signal context, but we
539 * do make an effort to keep the failure surface minimized, and this in-effect
540 * should catch any regressions in that effort. The odds of a logged message
541 * in a signal handler causing a lockup problem should be _very_ small.
542 */
543static void caught_blocking_signal(int /*signum*/)
Mark Salyzyncef098e2014-01-09 09:02:55 -0800544{
545 unsigned long long v = 0xDEADBEEFA55A0000ULL;
546
547 v += getpid() & 0xFFFF;
548
549 ++signaled;
550 if ((signal_time.tv_sec == 0) && (signal_time.tv_nsec == 0)) {
Mark Salyzyn7e2f83c2014-03-05 07:41:49 -0800551 signal_time = log_time(CLOCK_MONOTONIC);
Mark Salyzyncef098e2014-01-09 09:02:55 -0800552 signal_time.tv_sec += 2;
553 }
554
555 LOG_FAILURE_RETRY(__android_log_btwrite(0, EVENT_TYPE_LONG, &v, sizeof(v)));
556}
557
558// Fill in current process user and system time in 10ms increments
559static void get_ticks(unsigned long long *uticks, unsigned long long *sticks)
560{
561 *uticks = *sticks = 0;
562
563 pid_t pid = getpid();
564
565 char buffer[512];
566 snprintf(buffer, sizeof(buffer), "/proc/%u/stat", pid);
567
568 FILE *fp = fopen(buffer, "r");
569 if (!fp) {
570 return;
571 }
572
573 char *cp = fgets(buffer, sizeof(buffer), fp);
574 fclose(fp);
575 if (!cp) {
576 return;
577 }
578
579 pid_t d;
580 char s[sizeof(buffer)];
581 char c;
582 long long ll;
583 unsigned long long ull;
584
585 if (15 != sscanf(buffer,
586 "%d %s %c %lld %lld %lld %lld %lld %llu %llu %llu %llu %llu %llu %llu ",
587 &d, s, &c, &ll, &ll, &ll, &ll, &ll, &ull, &ull, &ull, &ull, &ull,
588 uticks, sticks)) {
589 *uticks = *sticks = 0;
590 }
591}
592
Mark Salyzyn50af7f82016-03-10 15:25:14 -0800593TEST(liblog, android_logger_list_read__cpu_signal) {
Mark Salyzyncef098e2014-01-09 09:02:55 -0800594 struct logger_list *logger_list;
595 unsigned long long v = 0xDEADBEEFA55A0000ULL;
596
597 pid_t pid = getpid();
598
599 v += pid & 0xFFFF;
600
Mark Salyzyn8196be32014-03-18 17:10:47 -0700601 ASSERT_TRUE(NULL != (logger_list = android_logger_list_open(
Mark Salyzyn2d3f38a2015-01-26 10:46:44 -0800602 LOG_ID_EVENTS, ANDROID_LOG_RDONLY, 1000, pid)));
Mark Salyzyncef098e2014-01-09 09:02:55 -0800603
604 int count = 0;
605
606 int signals = 0;
607
608 unsigned long long uticks_start;
609 unsigned long long sticks_start;
610 get_ticks(&uticks_start, &sticks_start);
611
612 const unsigned alarm_time = 10;
613
614 memset(&signal_time, 0, sizeof(signal_time));
615
Mark Salyzyn50af7f82016-03-10 15:25:14 -0800616 signal(SIGALRM, caught_blocking_signal);
Mark Salyzyncef098e2014-01-09 09:02:55 -0800617 alarm(alarm_time);
618
619 signaled = 0;
620
621 do {
622 log_msg log_msg;
623 if (android_logger_list_read(logger_list, &log_msg) <= 0) {
624 break;
625 }
626
627 alarm(alarm_time);
628
629 ++count;
630
631 ASSERT_EQ(log_msg.entry.pid, pid);
632
633 if ((log_msg.entry.len != (4 + 1 + 8))
634 || (log_msg.id() != LOG_ID_EVENTS)) {
635 continue;
636 }
637
638 char *eventData = log_msg.msg();
639
640 if (eventData[4] != EVENT_TYPE_LONG) {
641 continue;
642 }
643
644 unsigned long long l = eventData[4 + 1 + 0] & 0xFF;
645 l |= (unsigned long long) (eventData[4 + 1 + 1] & 0xFF) << 8;
646 l |= (unsigned long long) (eventData[4 + 1 + 2] & 0xFF) << 16;
647 l |= (unsigned long long) (eventData[4 + 1 + 3] & 0xFF) << 24;
648 l |= (unsigned long long) (eventData[4 + 1 + 4] & 0xFF) << 32;
649 l |= (unsigned long long) (eventData[4 + 1 + 5] & 0xFF) << 40;
650 l |= (unsigned long long) (eventData[4 + 1 + 6] & 0xFF) << 48;
651 l |= (unsigned long long) (eventData[4 + 1 + 7] & 0xFF) << 56;
652
653 if (l == v) {
654 ++signals;
655 break;
656 }
Mark Salyzyn8196be32014-03-18 17:10:47 -0700657 } while (!signaled || (log_time(CLOCK_MONOTONIC) < signal_time));
Mark Salyzyncef098e2014-01-09 09:02:55 -0800658 alarm(0);
659 signal(SIGALRM, SIG_DFL);
660
Mark Salyzyn50af7f82016-03-10 15:25:14 -0800661 EXPECT_LE(1, count);
662
663 EXPECT_EQ(1, signals);
664
665 android_logger_list_close(logger_list);
666
667 unsigned long long uticks_end;
668 unsigned long long sticks_end;
669 get_ticks(&uticks_end, &sticks_end);
670
671 // Less than 1% in either user or system time, or both
672 const unsigned long long one_percent_ticks = alarm_time;
673 unsigned long long user_ticks = uticks_end - uticks_start;
674 unsigned long long system_ticks = sticks_end - sticks_start;
675 EXPECT_GT(one_percent_ticks, user_ticks);
676 EXPECT_GT(one_percent_ticks, system_ticks);
677 EXPECT_GT(one_percent_ticks, user_ticks + system_ticks);
678}
679
680/*
681 * Strictly, we are not allowed to log messages in a signal context, the
682 * correct way to handle this is to ensure the messages are constructed in
683 * a thread; the signal handler should only unblock the thread.
684 */
685static sem_t thread_trigger;
686
687static void caught_blocking_thread(int /*signum*/)
688{
689 sem_post(&thread_trigger);
690}
691
692static void *running_thread(void *) {
693 unsigned long long v = 0xDEADBEAFA55A0000ULL;
694
695 v += getpid() & 0xFFFF;
696
697 struct timespec timeout;
698 clock_gettime(CLOCK_REALTIME, &timeout);
699 timeout.tv_sec += 55;
700 sem_timedwait(&thread_trigger, &timeout);
701
702 ++signaled;
703 if ((signal_time.tv_sec == 0) && (signal_time.tv_nsec == 0)) {
704 signal_time = log_time(CLOCK_MONOTONIC);
705 signal_time.tv_sec += 2;
706 }
707
708 LOG_FAILURE_RETRY(__android_log_btwrite(0, EVENT_TYPE_LONG, &v, sizeof(v)));
709
710 return NULL;
711}
712
713int start_thread()
714{
715 sem_init(&thread_trigger, 0, 0);
716
717 pthread_attr_t attr;
718 if (pthread_attr_init(&attr)) {
719 return -1;
720 }
721
722 struct sched_param param;
723
724 memset(&param, 0, sizeof(param));
725 pthread_attr_setschedparam(&attr, &param);
726 pthread_attr_setschedpolicy(&attr, SCHED_BATCH);
727
728 if (pthread_attr_setdetachstate(&attr, PTHREAD_CREATE_DETACHED)) {
729 pthread_attr_destroy(&attr);
730 return -1;
731 }
732
733 pthread_t thread;
734 if (pthread_create(&thread, &attr, running_thread, NULL)) {
735 pthread_attr_destroy(&attr);
736 return -1;
737 }
738
739 pthread_attr_destroy(&attr);
740 return 0;
741}
742
743TEST(liblog, android_logger_list_read__cpu_thread) {
744 struct logger_list *logger_list;
745 unsigned long long v = 0xDEADBEAFA55A0000ULL;
746
747 pid_t pid = getpid();
748
749 v += pid & 0xFFFF;
750
751 ASSERT_TRUE(NULL != (logger_list = android_logger_list_open(
752 LOG_ID_EVENTS, ANDROID_LOG_RDONLY, 1000, pid)));
753
754 int count = 0;
755
756 int signals = 0;
757
758 unsigned long long uticks_start;
759 unsigned long long sticks_start;
760 get_ticks(&uticks_start, &sticks_start);
761
762 const unsigned alarm_time = 10;
763
764 memset(&signal_time, 0, sizeof(signal_time));
765
766 signaled = 0;
767 EXPECT_EQ(0, start_thread());
768
769 signal(SIGALRM, caught_blocking_thread);
770 alarm(alarm_time);
771
772 do {
773 log_msg log_msg;
774 if (LOG_FAILURE_RETRY(android_logger_list_read(logger_list, &log_msg)) <= 0) {
775 break;
776 }
777
778 alarm(alarm_time);
779
780 ++count;
781
782 ASSERT_EQ(log_msg.entry.pid, pid);
783
784 if ((log_msg.entry.len != (4 + 1 + 8))
785 || (log_msg.id() != LOG_ID_EVENTS)) {
786 continue;
787 }
788
789 char *eventData = log_msg.msg();
790
791 if (eventData[4] != EVENT_TYPE_LONG) {
792 continue;
793 }
794
795 unsigned long long l = eventData[4 + 1 + 0] & 0xFF;
796 l |= (unsigned long long) (eventData[4 + 1 + 1] & 0xFF) << 8;
797 l |= (unsigned long long) (eventData[4 + 1 + 2] & 0xFF) << 16;
798 l |= (unsigned long long) (eventData[4 + 1 + 3] & 0xFF) << 24;
799 l |= (unsigned long long) (eventData[4 + 1 + 4] & 0xFF) << 32;
800 l |= (unsigned long long) (eventData[4 + 1 + 5] & 0xFF) << 40;
801 l |= (unsigned long long) (eventData[4 + 1 + 6] & 0xFF) << 48;
802 l |= (unsigned long long) (eventData[4 + 1 + 7] & 0xFF) << 56;
803
804 if (l == v) {
805 ++signals;
806 break;
807 }
808 } while (!signaled || (log_time(CLOCK_MONOTONIC) < signal_time));
809 alarm(0);
810 signal(SIGALRM, SIG_DFL);
811
812 EXPECT_LE(1, count);
Mark Salyzyncef098e2014-01-09 09:02:55 -0800813
Mark Salyzyn8196be32014-03-18 17:10:47 -0700814 EXPECT_EQ(1, signals);
Mark Salyzyncef098e2014-01-09 09:02:55 -0800815
816 android_logger_list_close(logger_list);
817
818 unsigned long long uticks_end;
819 unsigned long long sticks_end;
820 get_ticks(&uticks_end, &sticks_end);
821
822 // Less than 1% in either user or system time, or both
823 const unsigned long long one_percent_ticks = alarm_time;
824 unsigned long long user_ticks = uticks_end - uticks_start;
825 unsigned long long system_ticks = sticks_end - sticks_start;
Mark Salyzyn8196be32014-03-18 17:10:47 -0700826 EXPECT_GT(one_percent_ticks, user_ticks);
827 EXPECT_GT(one_percent_ticks, system_ticks);
828 EXPECT_GT(one_percent_ticks, user_ticks + system_ticks);
829}
830
Mark Salyzyn3f941222016-02-10 07:26:43 -0800831static const char max_payload_tag[] = "TEST_max_payload_and_longish_tag_XXXX";
Mark Salyzyn42ae8272015-12-03 15:37:00 -0800832#define SIZEOF_MAX_PAYLOAD_BUF (LOGGER_ENTRY_MAX_PAYLOAD - \
833 sizeof(max_payload_tag) - 1)
834static const char max_payload_buf[] = "LEONATO\n\
Mark Salyzyn8196be32014-03-18 17:10:47 -0700835I learn in this letter that Don Peter of Arragon\n\
836comes this night to Messina\n\
837MESSENGER\n\
838He is very near by this: he was not three leagues off\n\
839when I left him\n\
840LEONATO\n\
841How many gentlemen have you lost in this action?\n\
842MESSENGER\n\
843But few of any sort, and none of name\n\
844LEONATO\n\
845A victory is twice itself when the achiever brings\n\
846home full numbers. I find here that Don Peter hath\n\
847bestowed much honour on a young Florentine called Claudio\n\
848MESSENGER\n\
849Much deserved on his part and equally remembered by\n\
850Don Pedro: he hath borne himself beyond the\n\
851promise of his age, doing, in the figure of a lamb,\n\
852the feats of a lion: he hath indeed better\n\
853bettered expectation than you must expect of me to\n\
854tell you how\n\
855LEONATO\n\
856He hath an uncle here in Messina will be very much\n\
857glad of it.\n\
858MESSENGER\n\
859I have already delivered him letters, and there\n\
860appears much joy in him; even so much that joy could\n\
861not show itself modest enough without a badge of\n\
862bitterness.\n\
863LEONATO\n\
864Did he break out into tears?\n\
865MESSENGER\n\
866In great measure.\n\
867LEONATO\n\
868A kind overflow of kindness: there are no faces\n\
869truer than those that are so washed. How much\n\
870better is it to weep at joy than to joy at weeping!\n\
871BEATRICE\n\
872I pray you, is Signior Mountanto returned from the\n\
873wars or no?\n\
874MESSENGER\n\
875I know none of that name, lady: there was none such\n\
876in the army of any sort.\n\
877LEONATO\n\
878What is he that you ask for, niece?\n\
879HERO\n\
880My cousin means Signior Benedick of Padua.\n\
881MESSENGER\n\
882O, he's returned; and as pleasant as ever he was.\n\
883BEATRICE\n\
884He set up his bills here in Messina and challenged\n\
885Cupid at the flight; and my uncle's fool, reading\n\
886the challenge, subscribed for Cupid, and challenged\n\
887him at the bird-bolt. I pray you, how many hath he\n\
888killed and eaten in these wars? But how many hath\n\
889he killed? for indeed I promised to eat all of his killing.\n\
890LEONATO\n\
891Faith, niece, you tax Signior Benedick too much;\n\
892but he'll be meet with you, I doubt it not.\n\
893MESSENGER\n\
894He hath done good service, lady, in these wars.\n\
895BEATRICE\n\
896You had musty victual, and he hath holp to eat it:\n\
897he is a very valiant trencherman; he hath an\n\
898excellent stomach.\n\
899MESSENGER\n\
900And a good soldier too, lady.\n\
901BEATRICE\n\
902And a good soldier to a lady: but what is he to a lord?\n\
903MESSENGER\n\
904A lord to a lord, a man to a man; stuffed with all\n\
905honourable virtues.\n\
906BEATRICE\n\
907It is so, indeed; he is no less than a stuffed man:\n\
908but for the stuffing,--well, we are all mortal.\n\
909LEONATO\n\
910You must not, sir, mistake my niece. There is a\n\
911kind of merry war betwixt Signior Benedick and her:\n\
912they never meet but there's a skirmish of wit\n\
913between them.\n\
914BEATRICE\n\
915Alas! he gets nothing by that. In our last\n\
916conflict four of his five wits went halting off, and\n\
917now is the whole man governed with one: so that if\n\
918he have wit enough to keep himself warm, let him\n\
919bear it for a difference between himself and his\n\
920horse; for it is all the wealth that he hath left,\n\
921to be known a reasonable creature. Who is his\n\
922companion now? He hath every month a new sworn brother.\n\
923MESSENGER\n\
924Is't possible?\n\
925BEATRICE\n\
926Very easily possible: he wears his faith but as\n\
927the fashion of his hat; it ever changes with the\n\
928next block.\n\
929MESSENGER\n\
930I see, lady, the gentleman is not in your books.\n\
931BEATRICE\n\
932No; an he were, I would burn my study. But, I pray\n\
933you, who is his companion? Is there no young\n\
934squarer now that will make a voyage with him to the devil?\n\
935MESSENGER\n\
936He is most in the company of the right noble Claudio.\n\
937BEATRICE\n\
938O Lord, he will hang upon him like a disease: he\n\
939is sooner caught than the pestilence, and the taker\n\
940runs presently mad. God help the noble Claudio! if\n\
941he have caught the Benedick, it will cost him a\n\
942thousand pound ere a' be cured.\n\
943MESSENGER\n\
944I will hold friends with you, lady.\n\
945BEATRICE\n\
946Do, good friend.\n\
947LEONATO\n\
948You will never run mad, niece.\n\
949BEATRICE\n\
950No, not till a hot January.\n\
951MESSENGER\n\
952Don Pedro is approached.\n\
953Enter DON PEDRO, DON JOHN, CLAUDIO, BENEDICK, and BALTHASAR\n\
954\n\
955DON PEDRO\n\
956Good Signior Leonato, you are come to meet your\n\
957trouble: the fashion of the world is to avoid\n\
958cost, and you encounter it\n\
959LEONATO\n\
Mark Salyzynd4b061b2016-03-10 09:50:08 -0800960Never came trouble to my house in the likeness of your grace,\n\
961for trouble being gone, comfort should remain, but\n\
962when you depart from me, sorrow abides and happiness\n\
963takes his leave.";
Mark Salyzyn8196be32014-03-18 17:10:47 -0700964
965TEST(liblog, max_payload) {
966 pid_t pid = getpid();
967 char tag[sizeof(max_payload_tag)];
968 memcpy(tag, max_payload_tag, sizeof(tag));
969 snprintf(tag + sizeof(tag) - 5, 5, "%04X", pid & 0xFFFF);
970
971 LOG_FAILURE_RETRY(__android_log_buf_write(LOG_ID_SYSTEM, ANDROID_LOG_INFO,
972 tag, max_payload_buf));
Mark Salyzync1584562015-03-12 15:46:29 -0700973 sleep(2);
Mark Salyzyn8196be32014-03-18 17:10:47 -0700974
975 struct logger_list *logger_list;
976
977 ASSERT_TRUE(NULL != (logger_list = android_logger_list_open(
Mark Salyzyn2d3f38a2015-01-26 10:46:44 -0800978 LOG_ID_SYSTEM, ANDROID_LOG_RDONLY, 100, 0)));
Mark Salyzyn8196be32014-03-18 17:10:47 -0700979
980 bool matches = false;
981 ssize_t max_len = 0;
982
983 for(;;) {
984 log_msg log_msg;
985 if (android_logger_list_read(logger_list, &log_msg) <= 0) {
986 break;
987 }
988
989 if ((log_msg.entry.pid != pid) || (log_msg.id() != LOG_ID_SYSTEM)) {
990 continue;
991 }
992
993 char *data = log_msg.msg() + 1;
994
995 if (strcmp(data, tag)) {
996 continue;
997 }
998
999 data += strlen(data) + 1;
1000
1001 const char *left = data;
1002 const char *right = max_payload_buf;
1003 while (*left && *right && (*left == *right)) {
1004 ++left;
1005 ++right;
1006 }
1007
1008 if (max_len <= (left - data)) {
1009 max_len = left - data + 1;
1010 }
1011
1012 if (max_len > 512) {
1013 matches = true;
1014 break;
1015 }
1016 }
1017
Mark Salyzyn8444eb82014-04-24 09:43:23 -07001018 android_logger_list_close(logger_list);
1019
Mark Salyzyn8196be32014-03-18 17:10:47 -07001020 EXPECT_EQ(true, matches);
1021
Mark Salyzyn42ae8272015-12-03 15:37:00 -08001022 EXPECT_LE(SIZEOF_MAX_PAYLOAD_BUF, static_cast<size_t>(max_len));
Mark Salyzyn8444eb82014-04-24 09:43:23 -07001023}
1024
Mark Salyzyn2f83d672016-03-11 12:06:12 -08001025TEST(liblog, __android_log_buf_print__maxtag) {
1026 struct logger_list *logger_list;
1027
1028 pid_t pid = getpid();
1029
1030 ASSERT_TRUE(NULL != (logger_list = android_logger_list_open(
1031 LOG_ID_MAIN, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 1000, pid)));
1032
1033 log_time ts(android_log_clockid());
1034
1035 EXPECT_LT(0, __android_log_buf_print(LOG_ID_MAIN, ANDROID_LOG_INFO,
1036 max_payload_buf, max_payload_buf));
1037 usleep(1000000);
1038
1039 int count = 0;
1040
1041 for (;;) {
1042 log_msg log_msg;
1043 if (android_logger_list_read(logger_list, &log_msg) <= 0) {
1044 break;
1045 }
1046
1047 ASSERT_EQ(log_msg.entry.pid, pid);
1048
1049 if ((log_msg.entry.sec < (ts.tv_sec - 1))
1050 || ((ts.tv_sec + 1) < log_msg.entry.sec)
1051 || ((size_t)log_msg.entry.len < LOGGER_ENTRY_MAX_PAYLOAD)
1052 || (log_msg.id() != LOG_ID_MAIN)) {
1053 continue;
1054 }
1055
1056 ++count;
1057
1058 AndroidLogFormat *logformat = android_log_format_new();
1059 EXPECT_TRUE(NULL != logformat);
1060 AndroidLogEntry entry;
1061 int processLogBuffer = android_log_processLogBuffer(&log_msg.entry_v1,
1062 &entry);
1063 EXPECT_EQ(0, processLogBuffer);
1064 if (processLogBuffer == 0) {
1065 fflush(stderr);
1066 int printLogLine =
1067 android_log_printLogLine(logformat, fileno(stderr), &entry);
Mark Salyzyn083c5342016-03-21 09:45:34 -07001068 // Legacy tag truncation
Mark Salyzyn2f83d672016-03-11 12:06:12 -08001069 EXPECT_LE(128, printLogLine);
Mark Salyzyn083c5342016-03-21 09:45:34 -07001070 // Measured maximum if we try to print part of the tag as message
1071 EXPECT_GT(LOGGER_ENTRY_MAX_PAYLOAD * 13 / 8, printLogLine);
Mark Salyzyn2f83d672016-03-11 12:06:12 -08001072 }
1073 android_log_format_free(logformat);
1074 }
1075
1076 EXPECT_EQ(1, count);
1077
1078 android_logger_list_close(logger_list);
1079}
1080
Mark Salyzyn8444eb82014-04-24 09:43:23 -07001081TEST(liblog, too_big_payload) {
1082 pid_t pid = getpid();
1083 static const char big_payload_tag[] = "TEST_big_payload_XXXX";
1084 char tag[sizeof(big_payload_tag)];
1085 memcpy(tag, big_payload_tag, sizeof(tag));
1086 snprintf(tag + sizeof(tag) - 5, 5, "%04X", pid & 0xFFFF);
1087
1088 std::string longString(3266519, 'x');
1089
1090 ssize_t ret = LOG_FAILURE_RETRY(__android_log_buf_write(LOG_ID_SYSTEM,
1091 ANDROID_LOG_INFO, tag, longString.c_str()));
1092
1093 struct logger_list *logger_list;
1094
1095 ASSERT_TRUE(NULL != (logger_list = android_logger_list_open(
Mark Salyzyn2d3f38a2015-01-26 10:46:44 -08001096 LOG_ID_SYSTEM, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 100, 0)));
Mark Salyzyn8444eb82014-04-24 09:43:23 -07001097
1098 ssize_t max_len = 0;
1099
1100 for(;;) {
1101 log_msg log_msg;
1102 if (android_logger_list_read(logger_list, &log_msg) <= 0) {
1103 break;
1104 }
1105
1106 if ((log_msg.entry.pid != pid) || (log_msg.id() != LOG_ID_SYSTEM)) {
1107 continue;
1108 }
1109
1110 char *data = log_msg.msg() + 1;
1111
1112 if (strcmp(data, tag)) {
1113 continue;
1114 }
1115
1116 data += strlen(data) + 1;
1117
1118 const char *left = data;
1119 const char *right = longString.c_str();
1120 while (*left && *right && (*left == *right)) {
1121 ++left;
1122 ++right;
1123 }
1124
1125 if (max_len <= (left - data)) {
1126 max_len = left - data + 1;
1127 }
1128 }
Mark Salyzyn8196be32014-03-18 17:10:47 -07001129
1130 android_logger_list_close(logger_list);
Mark Salyzyn8444eb82014-04-24 09:43:23 -07001131
1132 EXPECT_LE(LOGGER_ENTRY_MAX_PAYLOAD - sizeof(big_payload_tag),
1133 static_cast<size_t>(max_len));
1134
Ben Cheng43232922014-05-20 10:38:24 -07001135 EXPECT_EQ(ret, max_len + static_cast<ssize_t>(sizeof(big_payload_tag)));
Mark Salyzyn8196be32014-03-18 17:10:47 -07001136}
1137
1138TEST(liblog, dual_reader) {
1139 struct logger_list *logger_list1;
1140
1141 // >25 messages due to liblog.__android_log_buf_print__concurrentXX above.
1142 ASSERT_TRUE(NULL != (logger_list1 = android_logger_list_open(
Mark Salyzyn2d3f38a2015-01-26 10:46:44 -08001143 LOG_ID_MAIN, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 25, 0)));
Mark Salyzyn8196be32014-03-18 17:10:47 -07001144
1145 struct logger_list *logger_list2;
1146
1147 if (NULL == (logger_list2 = android_logger_list_open(
Mark Salyzyn2d3f38a2015-01-26 10:46:44 -08001148 LOG_ID_MAIN, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 15, 0))) {
Mark Salyzyn8196be32014-03-18 17:10:47 -07001149 android_logger_list_close(logger_list1);
1150 ASSERT_TRUE(NULL != logger_list2);
1151 }
1152
1153 int count1 = 0;
1154 bool done1 = false;
1155 int count2 = 0;
1156 bool done2 = false;
1157
1158 do {
1159 log_msg log_msg;
1160
1161 if (!done1) {
1162 if (android_logger_list_read(logger_list1, &log_msg) <= 0) {
1163 done1 = true;
1164 } else {
1165 ++count1;
1166 }
1167 }
1168
1169 if (!done2) {
1170 if (android_logger_list_read(logger_list2, &log_msg) <= 0) {
1171 done2 = true;
1172 } else {
1173 ++count2;
1174 }
1175 }
1176 } while ((!done1) || (!done2));
1177
1178 android_logger_list_close(logger_list1);
1179 android_logger_list_close(logger_list2);
1180
1181 EXPECT_EQ(25, count1);
1182 EXPECT_EQ(15, count2);
Mark Salyzyncef098e2014-01-09 09:02:55 -08001183}
1184
Mark Salyzyn819c58a2013-11-22 12:39:43 -08001185TEST(liblog, android_logger_get_) {
Mark Salyzyn2d3f38a2015-01-26 10:46:44 -08001186 struct logger_list * logger_list = android_logger_list_alloc(ANDROID_LOG_WRONLY, 0, 0);
Mark Salyzyn819c58a2013-11-22 12:39:43 -08001187
1188 for(int i = LOG_ID_MIN; i < LOG_ID_MAX; ++i) {
1189 log_id_t id = static_cast<log_id_t>(i);
1190 const char *name = android_log_id_to_name(id);
1191 if (id != android_name_to_log_id(name)) {
1192 continue;
1193 }
Mark Salyzync1584562015-03-12 15:46:29 -07001194 fprintf(stderr, "log buffer %s\r", name);
Mark Salyzyn819c58a2013-11-22 12:39:43 -08001195 struct logger * logger;
Mark Salyzyn8196be32014-03-18 17:10:47 -07001196 EXPECT_TRUE(NULL != (logger = android_logger_open(logger_list, id)));
1197 EXPECT_EQ(id, android_logger_get_id(logger));
Mark Salyzyn29e70a92016-03-10 15:25:14 -08001198 ssize_t get_log_size = android_logger_get_log_size(logger);
1199 /* security buffer is allowed to be denied */
1200 if (strcmp("security", name)) {
1201 EXPECT_LT(0, get_log_size);
1202 /* crash buffer is allowed to be empty, that is actually healthy! */
1203 EXPECT_LE((strcmp("crash", name)) != 0,
1204 android_logger_get_log_readable_size(logger));
1205 } else {
1206 EXPECT_NE(0, get_log_size);
1207 if (get_log_size < 0) {
1208 EXPECT_GT(0, android_logger_get_log_readable_size(logger));
1209 } else {
1210 EXPECT_LE(0, android_logger_get_log_readable_size(logger));
1211 }
Mark Salyzync1584562015-03-12 15:46:29 -07001212 }
Mark Salyzyn8196be32014-03-18 17:10:47 -07001213 EXPECT_LT(0, android_logger_get_log_version(logger));
Mark Salyzyn819c58a2013-11-22 12:39:43 -08001214 }
1215
1216 android_logger_list_close(logger_list);
1217}
Mark Salyzyn5045f572014-04-30 08:50:53 -07001218
1219static bool checkPriForTag(AndroidLogFormat *p_format, const char *tag, android_LogPriority pri) {
1220 return android_log_shouldPrintLine(p_format, tag, pri)
1221 && !android_log_shouldPrintLine(p_format, tag, (android_LogPriority)(pri - 1));
1222}
1223
1224TEST(liblog, filterRule) {
1225 static const char tag[] = "random";
1226
1227 AndroidLogFormat *p_format = android_log_format_new();
1228
1229 android_log_addFilterRule(p_format,"*:i");
1230
1231 EXPECT_TRUE(checkPriForTag(p_format, tag, ANDROID_LOG_INFO));
1232 EXPECT_TRUE(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) == 0);
1233 android_log_addFilterRule(p_format, "*");
1234 EXPECT_TRUE (checkPriForTag(p_format, tag, ANDROID_LOG_DEBUG));
1235 EXPECT_TRUE(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) > 0);
1236 android_log_addFilterRule(p_format, "*:v");
1237 EXPECT_TRUE (checkPriForTag(p_format, tag, ANDROID_LOG_VERBOSE));
1238 EXPECT_TRUE(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) > 0);
1239 android_log_addFilterRule(p_format, "*:i");
1240 EXPECT_TRUE (checkPriForTag(p_format, tag, ANDROID_LOG_INFO));
1241 EXPECT_TRUE(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) == 0);
1242
1243 android_log_addFilterRule(p_format, tag);
1244 EXPECT_TRUE (checkPriForTag(p_format, tag, ANDROID_LOG_VERBOSE));
1245 EXPECT_TRUE(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) > 0);
1246 android_log_addFilterRule(p_format, "random:v");
1247 EXPECT_TRUE (checkPriForTag(p_format, tag, ANDROID_LOG_VERBOSE));
1248 EXPECT_TRUE(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) > 0);
1249 android_log_addFilterRule(p_format, "random:d");
1250 EXPECT_TRUE (checkPriForTag(p_format, tag, ANDROID_LOG_DEBUG));
1251 EXPECT_TRUE(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) > 0);
1252 android_log_addFilterRule(p_format, "random:w");
1253 EXPECT_TRUE (checkPriForTag(p_format, tag, ANDROID_LOG_WARN));
1254 EXPECT_TRUE(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) == 0);
1255
1256 android_log_addFilterRule(p_format, "crap:*");
1257 EXPECT_TRUE (checkPriForTag(p_format, "crap", ANDROID_LOG_VERBOSE));
1258 EXPECT_TRUE(android_log_shouldPrintLine(p_format, "crap", ANDROID_LOG_VERBOSE) > 0);
1259
1260 // invalid expression
1261 EXPECT_TRUE (android_log_addFilterRule(p_format, "random:z") < 0);
1262 EXPECT_TRUE (checkPriForTag(p_format, tag, ANDROID_LOG_WARN));
1263 EXPECT_TRUE(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) == 0);
1264
1265 // Issue #550946
1266 EXPECT_TRUE(android_log_addFilterString(p_format, " ") == 0);
1267 EXPECT_TRUE(checkPriForTag(p_format, tag, ANDROID_LOG_WARN));
1268
1269 // note trailing space
1270 EXPECT_TRUE(android_log_addFilterString(p_format, "*:s random:d ") == 0);
1271 EXPECT_TRUE(checkPriForTag(p_format, tag, ANDROID_LOG_DEBUG));
1272
1273 EXPECT_TRUE(android_log_addFilterString(p_format, "*:s random:z") < 0);
1274
1275#if 0 // bitrot, seek update
1276 char defaultBuffer[512];
1277
1278 android_log_formatLogLine(p_format,
1279 defaultBuffer, sizeof(defaultBuffer), 0, ANDROID_LOG_ERROR, 123,
1280 123, 123, tag, "nofile", strlen("Hello"), "Hello", NULL);
1281
1282 fprintf(stderr, "%s\n", defaultBuffer);
1283#endif
1284
1285 android_log_format_free(p_format);
1286}
Mark Salyzync1584562015-03-12 15:46:29 -07001287
1288TEST(liblog, is_loggable) {
1289 static const char tag[] = "is_loggable";
1290 static const char log_namespace[] = "persist.log.tag.";
1291 static const size_t base_offset = 8; /* skip "persist." */
1292 // sizeof("string") = strlen("string") + 1
1293 char key[sizeof(log_namespace) + sizeof(tag) - 1];
1294 char hold[4][PROP_VALUE_MAX];
1295 static const struct {
1296 int level;
1297 char type;
1298 } levels[] = {
1299 { ANDROID_LOG_VERBOSE, 'v' },
1300 { ANDROID_LOG_DEBUG , 'd' },
1301 { ANDROID_LOG_INFO , 'i' },
1302 { ANDROID_LOG_WARN , 'w' },
1303 { ANDROID_LOG_ERROR , 'e' },
1304 { ANDROID_LOG_FATAL , 'a' },
1305 { -1 , 's' },
1306 { -2 , 'g' }, // Illegal value, resort to default
1307 };
1308
1309 // Set up initial test condition
1310 memset(hold, 0, sizeof(hold));
1311 snprintf(key, sizeof(key), "%s%s", log_namespace, tag);
1312 property_get(key, hold[0], "");
1313 property_set(key, "");
1314 property_get(key + base_offset, hold[1], "");
1315 property_set(key + base_offset, "");
1316 strcpy(key, log_namespace);
1317 key[sizeof(log_namespace) - 2] = '\0';
1318 property_get(key, hold[2], "");
1319 property_set(key, "");
1320 property_get(key, hold[3], "");
1321 property_set(key + base_offset, "");
1322
1323 // All combinations of level and defaults
1324 for(size_t i = 0; i < (sizeof(levels) / sizeof(levels[0])); ++i) {
1325 if (levels[i].level == -2) {
1326 continue;
1327 }
1328 for(size_t j = 0; j < (sizeof(levels) / sizeof(levels[0])); ++j) {
1329 if (levels[j].level == -2) {
1330 continue;
1331 }
1332 fprintf(stderr, "i=%zu j=%zu\r", i, j);
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001333 bool android_log_is_loggable = __android_log_is_loggable(
1334 levels[i].level, tag, levels[j].level);
Mark Salyzync1584562015-03-12 15:46:29 -07001335 if ((levels[i].level < levels[j].level)
1336 || (levels[j].level == -1)) {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001337 if (android_log_is_loggable) {
1338 fprintf(stderr, "\n");
1339 }
1340 EXPECT_FALSE(android_log_is_loggable);
Mark Salyzynefe8ecc2016-04-14 15:31:56 -07001341 for(size_t k = 10; k; --k) {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001342 EXPECT_FALSE(__android_log_is_loggable(
1343 levels[i].level, tag, levels[j].level));
1344 }
Mark Salyzync1584562015-03-12 15:46:29 -07001345 } else {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001346 if (!android_log_is_loggable) {
1347 fprintf(stderr, "\n");
1348 }
1349 EXPECT_TRUE(android_log_is_loggable);
Mark Salyzynefe8ecc2016-04-14 15:31:56 -07001350 for(size_t k = 10; k; --k) {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001351 EXPECT_TRUE(__android_log_is_loggable(
1352 levels[i].level, tag, levels[j].level));
1353 }
Mark Salyzync1584562015-03-12 15:46:29 -07001354 }
1355 }
1356 }
1357
1358 // All combinations of level and tag and global properties
1359 for(size_t i = 0; i < (sizeof(levels) / sizeof(levels[0])); ++i) {
1360 if (levels[i].level == -2) {
1361 continue;
1362 }
1363 for(size_t j = 0; j < (sizeof(levels) / sizeof(levels[0])); ++j) {
1364 char buf[2];
1365 buf[0] = levels[j].type;
1366 buf[1] = '\0';
1367
1368 snprintf(key, sizeof(key), "%s%s", log_namespace, tag);
1369 fprintf(stderr, "i=%zu j=%zu property_set(\"%s\",\"%s\")\r",
1370 i, j, key, buf);
Mark Salyzyn5cceee62016-04-29 10:21:07 -07001371 usleep(20000);
Mark Salyzync1584562015-03-12 15:46:29 -07001372 property_set(key, buf);
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001373 bool android_log_is_loggable = __android_log_is_loggable(
1374 levels[i].level, tag, ANDROID_LOG_DEBUG);
Mark Salyzync1584562015-03-12 15:46:29 -07001375 if ((levels[i].level < levels[j].level)
1376 || (levels[j].level == -1)
1377 || ((levels[i].level < ANDROID_LOG_DEBUG)
1378 && (levels[j].level == -2))) {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001379 if (android_log_is_loggable) {
1380 fprintf(stderr, "\n");
1381 }
1382 EXPECT_FALSE(android_log_is_loggable);
Mark Salyzynefe8ecc2016-04-14 15:31:56 -07001383 for(size_t k = 10; k; --k) {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001384 EXPECT_FALSE(__android_log_is_loggable(
1385 levels[i].level, tag, ANDROID_LOG_DEBUG));
1386 }
Mark Salyzync1584562015-03-12 15:46:29 -07001387 } else {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001388 if (!android_log_is_loggable) {
1389 fprintf(stderr, "\n");
1390 }
1391 EXPECT_TRUE(android_log_is_loggable);
Mark Salyzynefe8ecc2016-04-14 15:31:56 -07001392 for(size_t k = 10; k; --k) {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001393 EXPECT_TRUE(__android_log_is_loggable(
1394 levels[i].level, tag, ANDROID_LOG_DEBUG));
1395 }
Mark Salyzync1584562015-03-12 15:46:29 -07001396 }
Mark Salyzyn5cceee62016-04-29 10:21:07 -07001397 usleep(20000);
Mark Salyzync1584562015-03-12 15:46:29 -07001398 property_set(key, "");
1399
1400 fprintf(stderr, "i=%zu j=%zu property_set(\"%s\",\"%s\")\r",
1401 i, j, key + base_offset, buf);
1402 property_set(key + base_offset, buf);
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001403 android_log_is_loggable = __android_log_is_loggable(
1404 levels[i].level, tag, ANDROID_LOG_DEBUG);
Mark Salyzync1584562015-03-12 15:46:29 -07001405 if ((levels[i].level < levels[j].level)
1406 || (levels[j].level == -1)
1407 || ((levels[i].level < ANDROID_LOG_DEBUG)
1408 && (levels[j].level == -2))) {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001409 if (android_log_is_loggable) {
1410 fprintf(stderr, "\n");
1411 }
1412 EXPECT_FALSE(android_log_is_loggable);
Mark Salyzynefe8ecc2016-04-14 15:31:56 -07001413 for(size_t k = 10; k; --k) {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001414 EXPECT_FALSE(__android_log_is_loggable(
1415 levels[i].level, tag, ANDROID_LOG_DEBUG));
1416 }
Mark Salyzync1584562015-03-12 15:46:29 -07001417 } else {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001418 if (!android_log_is_loggable) {
1419 fprintf(stderr, "\n");
1420 }
1421 EXPECT_TRUE(android_log_is_loggable);
Mark Salyzynefe8ecc2016-04-14 15:31:56 -07001422 for(size_t k = 10; k; --k) {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001423 EXPECT_TRUE(__android_log_is_loggable(
1424 levels[i].level, tag, ANDROID_LOG_DEBUG));
1425 }
Mark Salyzync1584562015-03-12 15:46:29 -07001426 }
Mark Salyzyn5cceee62016-04-29 10:21:07 -07001427 usleep(20000);
Mark Salyzync1584562015-03-12 15:46:29 -07001428 property_set(key + base_offset, "");
1429
1430 strcpy(key, log_namespace);
1431 key[sizeof(log_namespace) - 2] = '\0';
1432 fprintf(stderr, "i=%zu j=%zu property_set(\"%s\",\"%s\")\r",
1433 i, j, key, buf);
1434 property_set(key, buf);
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001435 android_log_is_loggable = __android_log_is_loggable(
1436 levels[i].level, tag, ANDROID_LOG_DEBUG);
Mark Salyzync1584562015-03-12 15:46:29 -07001437 if ((levels[i].level < levels[j].level)
1438 || (levels[j].level == -1)
1439 || ((levels[i].level < ANDROID_LOG_DEBUG)
1440 && (levels[j].level == -2))) {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001441 if (android_log_is_loggable) {
1442 fprintf(stderr, "\n");
1443 }
1444 EXPECT_FALSE(android_log_is_loggable);
Mark Salyzynefe8ecc2016-04-14 15:31:56 -07001445 for(size_t k = 10; k; --k) {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001446 EXPECT_FALSE(__android_log_is_loggable(
1447 levels[i].level, tag, ANDROID_LOG_DEBUG));
1448 }
Mark Salyzync1584562015-03-12 15:46:29 -07001449 } else {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001450 if (!android_log_is_loggable) {
1451 fprintf(stderr, "\n");
1452 }
1453 EXPECT_TRUE(android_log_is_loggable);
Mark Salyzynefe8ecc2016-04-14 15:31:56 -07001454 for(size_t k = 10; k; --k) {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001455 EXPECT_TRUE(__android_log_is_loggable(
1456 levels[i].level, tag, ANDROID_LOG_DEBUG));
1457 }
Mark Salyzync1584562015-03-12 15:46:29 -07001458 }
Mark Salyzyn5cceee62016-04-29 10:21:07 -07001459 usleep(20000);
Mark Salyzync1584562015-03-12 15:46:29 -07001460 property_set(key, "");
1461
1462 fprintf(stderr, "i=%zu j=%zu property_set(\"%s\",\"%s\")\r",
1463 i, j, key + base_offset, buf);
1464 property_set(key + base_offset, buf);
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001465 android_log_is_loggable = __android_log_is_loggable(
1466 levels[i].level, tag, ANDROID_LOG_DEBUG);
Mark Salyzync1584562015-03-12 15:46:29 -07001467 if ((levels[i].level < levels[j].level)
1468 || (levels[j].level == -1)
1469 || ((levels[i].level < ANDROID_LOG_DEBUG)
1470 && (levels[j].level == -2))) {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001471 if (android_log_is_loggable) {
1472 fprintf(stderr, "\n");
1473 }
1474 EXPECT_FALSE(android_log_is_loggable);
Mark Salyzynefe8ecc2016-04-14 15:31:56 -07001475 for(size_t k = 10; k; --k) {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001476 EXPECT_FALSE(__android_log_is_loggable(
1477 levels[i].level, tag, ANDROID_LOG_DEBUG));
1478 }
Mark Salyzync1584562015-03-12 15:46:29 -07001479 } else {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001480 if (!android_log_is_loggable) {
1481 fprintf(stderr, "\n");
1482 }
1483 EXPECT_TRUE(android_log_is_loggable);
Mark Salyzynefe8ecc2016-04-14 15:31:56 -07001484 for(size_t k = 10; k; --k) {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001485 EXPECT_TRUE(__android_log_is_loggable(
1486 levels[i].level, tag, ANDROID_LOG_DEBUG));
1487 }
Mark Salyzync1584562015-03-12 15:46:29 -07001488 }
Mark Salyzyn5cceee62016-04-29 10:21:07 -07001489 usleep(20000);
Mark Salyzync1584562015-03-12 15:46:29 -07001490 property_set(key + base_offset, "");
1491 }
1492 }
1493
1494 // All combinations of level and tag properties, but with global set to INFO
1495 strcpy(key, log_namespace);
1496 key[sizeof(log_namespace) - 2] = '\0';
Mark Salyzyn5cceee62016-04-29 10:21:07 -07001497 usleep(20000);
Mark Salyzync1584562015-03-12 15:46:29 -07001498 property_set(key, "I");
1499 snprintf(key, sizeof(key), "%s%s", log_namespace, tag);
1500 for(size_t i = 0; i < (sizeof(levels) / sizeof(levels[0])); ++i) {
1501 if (levels[i].level == -2) {
1502 continue;
1503 }
1504 for(size_t j = 0; j < (sizeof(levels) / sizeof(levels[0])); ++j) {
1505 char buf[2];
1506 buf[0] = levels[j].type;
1507 buf[1] = '\0';
1508
1509 fprintf(stderr, "i=%zu j=%zu property_set(\"%s\",\"%s\")\r",
1510 i, j, key, buf);
Mark Salyzyn5cceee62016-04-29 10:21:07 -07001511 usleep(20000);
Mark Salyzync1584562015-03-12 15:46:29 -07001512 property_set(key, buf);
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001513 bool android_log_is_loggable = __android_log_is_loggable(
1514 levels[i].level, tag, ANDROID_LOG_DEBUG);
Mark Salyzync1584562015-03-12 15:46:29 -07001515 if ((levels[i].level < levels[j].level)
1516 || (levels[j].level == -1)
1517 || ((levels[i].level < ANDROID_LOG_INFO) // Yes INFO
1518 && (levels[j].level == -2))) {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001519 if (android_log_is_loggable) {
1520 fprintf(stderr, "\n");
1521 }
1522 EXPECT_FALSE(android_log_is_loggable);
Mark Salyzynefe8ecc2016-04-14 15:31:56 -07001523 for(size_t k = 10; k; --k) {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001524 EXPECT_FALSE(__android_log_is_loggable(
1525 levels[i].level, tag, ANDROID_LOG_DEBUG));
1526 }
Mark Salyzync1584562015-03-12 15:46:29 -07001527 } else {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001528 if (!android_log_is_loggable) {
1529 fprintf(stderr, "\n");
1530 }
1531 EXPECT_TRUE(android_log_is_loggable);
Mark Salyzynefe8ecc2016-04-14 15:31:56 -07001532 for(size_t k = 10; k; --k) {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001533 EXPECT_TRUE(__android_log_is_loggable(
1534 levels[i].level, tag, ANDROID_LOG_DEBUG));
1535 }
Mark Salyzync1584562015-03-12 15:46:29 -07001536 }
Mark Salyzyn5cceee62016-04-29 10:21:07 -07001537 usleep(20000);
Mark Salyzync1584562015-03-12 15:46:29 -07001538 property_set(key, "");
1539
1540 fprintf(stderr, "i=%zu j=%zu property_set(\"%s\",\"%s\")\r",
1541 i, j, key + base_offset, buf);
1542 property_set(key + base_offset, buf);
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001543 android_log_is_loggable = __android_log_is_loggable(
1544 levels[i].level, tag, ANDROID_LOG_DEBUG);
Mark Salyzync1584562015-03-12 15:46:29 -07001545 if ((levels[i].level < levels[j].level)
1546 || (levels[j].level == -1)
1547 || ((levels[i].level < ANDROID_LOG_INFO) // Yes INFO
1548 && (levels[j].level == -2))) {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001549 if (android_log_is_loggable) {
1550 fprintf(stderr, "\n");
1551 }
1552 EXPECT_FALSE(android_log_is_loggable);
Mark Salyzynefe8ecc2016-04-14 15:31:56 -07001553 for(size_t k = 10; k; --k) {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001554 EXPECT_FALSE(__android_log_is_loggable(
1555 levels[i].level, tag, ANDROID_LOG_DEBUG));
1556 }
Mark Salyzync1584562015-03-12 15:46:29 -07001557 } else {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001558 if (!android_log_is_loggable) {
1559 fprintf(stderr, "\n");
1560 }
1561 EXPECT_TRUE(android_log_is_loggable);
Mark Salyzynefe8ecc2016-04-14 15:31:56 -07001562 for(size_t k = 10; k; --k) {
Mark Salyzyn77c166b2015-12-07 16:09:22 -08001563 EXPECT_TRUE(__android_log_is_loggable(
1564 levels[i].level, tag, ANDROID_LOG_DEBUG));
1565 }
Mark Salyzync1584562015-03-12 15:46:29 -07001566 }
Mark Salyzyn5cceee62016-04-29 10:21:07 -07001567 usleep(20000);
Mark Salyzync1584562015-03-12 15:46:29 -07001568 property_set(key + base_offset, "");
1569 }
1570 }
1571
1572 // reset parms
1573 snprintf(key, sizeof(key), "%s%s", log_namespace, tag);
Mark Salyzyn5cceee62016-04-29 10:21:07 -07001574 usleep(20000);
Mark Salyzync1584562015-03-12 15:46:29 -07001575 property_set(key, hold[0]);
1576 property_set(key + base_offset, hold[1]);
1577 strcpy(key, log_namespace);
1578 key[sizeof(log_namespace) - 2] = '\0';
1579 property_set(key, hold[2]);
1580 property_set(key + base_offset, hold[3]);
1581}
William Luh964428c2015-08-13 10:41:58 -07001582
William Luh964428c2015-08-13 10:41:58 -07001583TEST(liblog, android_errorWriteWithInfoLog__android_logger_list_read__typical) {
1584 const int TAG = 123456781;
1585 const char SUBTAG[] = "test-subtag";
1586 const int UID = -1;
1587 const int DATA_LEN = 200;
1588 struct logger_list *logger_list;
1589
1590 pid_t pid = getpid();
1591
1592 ASSERT_TRUE(NULL != (logger_list = android_logger_list_open(
1593 LOG_ID_EVENTS, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 1000, pid)));
1594
1595 ASSERT_LT(0, android_errorWriteWithInfoLog(
1596 TAG, SUBTAG, UID, max_payload_buf, DATA_LEN));
1597
1598 sleep(2);
1599
1600 int count = 0;
1601
1602 for (;;) {
1603 log_msg log_msg;
1604 if (android_logger_list_read(logger_list, &log_msg) <= 0) {
1605 break;
1606 }
1607
1608 char *eventData = log_msg.msg();
1609
1610 // Tag
1611 int tag = get4LE(eventData);
1612 eventData += 4;
1613
1614 if (tag != TAG) {
1615 continue;
1616 }
1617
1618 // List type
1619 ASSERT_EQ(EVENT_TYPE_LIST, eventData[0]);
1620 eventData++;
1621
1622 // Number of elements in list
1623 ASSERT_EQ(3, eventData[0]);
1624 eventData++;
1625
1626 // Element #1: string type for subtag
1627 ASSERT_EQ(EVENT_TYPE_STRING, eventData[0]);
1628 eventData++;
1629
1630 ASSERT_EQ((int) strlen(SUBTAG), get4LE(eventData));
1631 eventData +=4;
1632
1633 if (memcmp(SUBTAG, eventData, strlen(SUBTAG))) {
1634 continue;
1635 }
1636 eventData += strlen(SUBTAG);
1637
1638 // Element #2: int type for uid
1639 ASSERT_EQ(EVENT_TYPE_INT, eventData[0]);
1640 eventData++;
1641
1642 ASSERT_EQ(UID, get4LE(eventData));
1643 eventData += 4;
1644
1645 // Element #3: string type for data
1646 ASSERT_EQ(EVENT_TYPE_STRING, eventData[0]);
1647 eventData++;
1648
1649 ASSERT_EQ(DATA_LEN, get4LE(eventData));
1650 eventData += 4;
1651
1652 if (memcmp(max_payload_buf, eventData, DATA_LEN)) {
1653 continue;
1654 }
1655
1656 ++count;
1657 }
1658
1659 EXPECT_EQ(1, count);
1660
1661 android_logger_list_close(logger_list);
1662}
1663
1664TEST(liblog, android_errorWriteWithInfoLog__android_logger_list_read__data_too_large) {
1665 const int TAG = 123456782;
1666 const char SUBTAG[] = "test-subtag";
1667 const int UID = -1;
Mark Salyzyn5cecedc2016-02-25 09:02:09 -08001668 const int DATA_LEN = sizeof(max_payload_buf);
William Luh964428c2015-08-13 10:41:58 -07001669 struct logger_list *logger_list;
1670
1671 pid_t pid = getpid();
1672
1673 ASSERT_TRUE(NULL != (logger_list = android_logger_list_open(
1674 LOG_ID_EVENTS, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 1000, pid)));
1675
1676 ASSERT_LT(0, android_errorWriteWithInfoLog(
1677 TAG, SUBTAG, UID, max_payload_buf, DATA_LEN));
1678
1679 sleep(2);
1680
1681 int count = 0;
1682
1683 for (;;) {
1684 log_msg log_msg;
1685 if (android_logger_list_read(logger_list, &log_msg) <= 0) {
1686 break;
1687 }
1688
1689 char *eventData = log_msg.msg();
1690 char *original = eventData;
1691
1692 // Tag
1693 int tag = get4LE(eventData);
1694 eventData += 4;
1695
1696 if (tag != TAG) {
1697 continue;
1698 }
1699
1700 // List type
1701 ASSERT_EQ(EVENT_TYPE_LIST, eventData[0]);
1702 eventData++;
1703
1704 // Number of elements in list
1705 ASSERT_EQ(3, eventData[0]);
1706 eventData++;
1707
1708 // Element #1: string type for subtag
1709 ASSERT_EQ(EVENT_TYPE_STRING, eventData[0]);
1710 eventData++;
1711
1712 ASSERT_EQ((int) strlen(SUBTAG), get4LE(eventData));
1713 eventData +=4;
1714
1715 if (memcmp(SUBTAG, eventData, strlen(SUBTAG))) {
1716 continue;
1717 }
1718 eventData += strlen(SUBTAG);
1719
1720 // Element #2: int type for uid
1721 ASSERT_EQ(EVENT_TYPE_INT, eventData[0]);
1722 eventData++;
1723
1724 ASSERT_EQ(UID, get4LE(eventData));
1725 eventData += 4;
1726
1727 // Element #3: string type for data
1728 ASSERT_EQ(EVENT_TYPE_STRING, eventData[0]);
1729 eventData++;
1730
1731 size_t dataLen = get4LE(eventData);
1732 eventData += 4;
1733
1734 if (memcmp(max_payload_buf, eventData, dataLen)) {
1735 continue;
1736 }
1737 eventData += dataLen;
1738
Mark Salyzyn5cecedc2016-02-25 09:02:09 -08001739 // 4 bytes for the tag, and max_payload_buf should be truncated.
1740 ASSERT_LE(4 + 512, eventData - original); // worst expectations
1741 ASSERT_GT(4 + DATA_LEN, eventData - original); // must be truncated
William Luh964428c2015-08-13 10:41:58 -07001742
1743 ++count;
1744 }
1745
1746 EXPECT_EQ(1, count);
1747
1748 android_logger_list_close(logger_list);
1749}
1750
1751TEST(liblog, android_errorWriteWithInfoLog__android_logger_list_read__null_data) {
1752 const int TAG = 123456783;
1753 const char SUBTAG[] = "test-subtag";
1754 const int UID = -1;
1755 const int DATA_LEN = 200;
1756 struct logger_list *logger_list;
1757
1758 pid_t pid = getpid();
1759
1760 ASSERT_TRUE(NULL != (logger_list = android_logger_list_open(
1761 LOG_ID_EVENTS, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 1000, pid)));
1762
1763 ASSERT_GT(0, android_errorWriteWithInfoLog(
1764 TAG, SUBTAG, UID, NULL, DATA_LEN));
1765
1766 sleep(2);
1767
1768 int count = 0;
1769
1770 for (;;) {
1771 log_msg log_msg;
1772 if (android_logger_list_read(logger_list, &log_msg) <= 0) {
1773 break;
1774 }
1775
1776 char *eventData = log_msg.msg();
1777
1778 // Tag
1779 int tag = get4LE(eventData);
1780 eventData += 4;
1781
1782 if (tag == TAG) {
1783 // This tag should not have been written because the data was null
1784 count++;
1785 break;
1786 }
1787 }
1788
1789 EXPECT_EQ(0, count);
1790
1791 android_logger_list_close(logger_list);
1792}
1793
1794TEST(liblog, android_errorWriteWithInfoLog__android_logger_list_read__subtag_too_long) {
1795 const int TAG = 123456784;
1796 const char SUBTAG[] = "abcdefghijklmnopqrstuvwxyz now i know my abc";
1797 const int UID = -1;
1798 const int DATA_LEN = 200;
1799 struct logger_list *logger_list;
1800
1801 pid_t pid = getpid();
1802
1803 ASSERT_TRUE(NULL != (logger_list = android_logger_list_open(
1804 LOG_ID_EVENTS, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 1000, pid)));
1805
1806 ASSERT_LT(0, android_errorWriteWithInfoLog(
1807 TAG, SUBTAG, UID, max_payload_buf, DATA_LEN));
1808
1809 sleep(2);
1810
1811 int count = 0;
1812
1813 for (;;) {
1814 log_msg log_msg;
1815 if (android_logger_list_read(logger_list, &log_msg) <= 0) {
1816 break;
1817 }
1818
1819 char *eventData = log_msg.msg();
1820
1821 // Tag
1822 int tag = get4LE(eventData);
1823 eventData += 4;
1824
1825 if (tag != TAG) {
1826 continue;
1827 }
1828
1829 // List type
1830 ASSERT_EQ(EVENT_TYPE_LIST, eventData[0]);
1831 eventData++;
1832
1833 // Number of elements in list
1834 ASSERT_EQ(3, eventData[0]);
1835 eventData++;
1836
1837 // Element #1: string type for subtag
1838 ASSERT_EQ(EVENT_TYPE_STRING, eventData[0]);
1839 eventData++;
1840
1841 // The subtag is longer than 32 and should be truncated to that.
1842 ASSERT_EQ(32, get4LE(eventData));
1843 eventData +=4;
1844
1845 if (memcmp(SUBTAG, eventData, 32)) {
1846 continue;
1847 }
1848 eventData += 32;
1849
1850 // Element #2: int type for uid
1851 ASSERT_EQ(EVENT_TYPE_INT, eventData[0]);
1852 eventData++;
1853
1854 ASSERT_EQ(UID, get4LE(eventData));
1855 eventData += 4;
1856
1857 // Element #3: string type for data
1858 ASSERT_EQ(EVENT_TYPE_STRING, eventData[0]);
1859 eventData++;
1860
1861 ASSERT_EQ(DATA_LEN, get4LE(eventData));
1862 eventData += 4;
1863
1864 if (memcmp(max_payload_buf, eventData, DATA_LEN)) {
1865 continue;
1866 }
1867
1868 ++count;
1869 }
1870
1871 EXPECT_EQ(1, count);
1872
1873 android_logger_list_close(logger_list);
1874}
1875
Mark Salyzyn66368722016-02-11 10:10:57 -08001876TEST(liblog, __android_log_bswrite_and_print___max) {
1877 bswrite_test(max_payload_buf);
1878}
1879
1880TEST(liblog, __android_log_buf_write_and_print__max) {
1881 buf_write_test(max_payload_buf);
1882}
1883
William Luh964428c2015-08-13 10:41:58 -07001884TEST(liblog, android_errorWriteLog__android_logger_list_read__success) {
1885 const int TAG = 123456785;
1886 const char SUBTAG[] = "test-subtag";
1887 struct logger_list *logger_list;
1888
1889 pid_t pid = getpid();
1890
1891 ASSERT_TRUE(NULL != (logger_list = android_logger_list_open(
1892 LOG_ID_EVENTS, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 1000, pid)));
1893
1894 ASSERT_LT(0, android_errorWriteLog(TAG, SUBTAG));
1895
1896 sleep(2);
1897
1898 int count = 0;
1899
1900 for (;;) {
1901 log_msg log_msg;
1902 if (android_logger_list_read(logger_list, &log_msg) <= 0) {
1903 break;
1904 }
1905
1906 char *eventData = log_msg.msg();
1907
1908 // Tag
1909 int tag = get4LE(eventData);
1910 eventData += 4;
1911
1912 if (tag != TAG) {
1913 continue;
1914 }
1915
1916 // List type
1917 ASSERT_EQ(EVENT_TYPE_LIST, eventData[0]);
1918 eventData++;
1919
1920 // Number of elements in list
1921 ASSERT_EQ(3, eventData[0]);
1922 eventData++;
1923
1924 // Element #1: string type for subtag
1925 ASSERT_EQ(EVENT_TYPE_STRING, eventData[0]);
1926 eventData++;
1927
1928 ASSERT_EQ((int) strlen(SUBTAG), get4LE(eventData));
1929 eventData +=4;
1930
1931 if (memcmp(SUBTAG, eventData, strlen(SUBTAG))) {
1932 continue;
1933 }
1934 ++count;
1935 }
1936
1937 EXPECT_EQ(1, count);
1938
1939 android_logger_list_close(logger_list);
1940}
1941
1942TEST(liblog, android_errorWriteLog__android_logger_list_read__null_subtag) {
1943 const int TAG = 123456786;
1944 struct logger_list *logger_list;
1945
1946 pid_t pid = getpid();
1947
1948 ASSERT_TRUE(NULL != (logger_list = android_logger_list_open(
1949 LOG_ID_EVENTS, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 1000, pid)));
1950
1951 ASSERT_GT(0, android_errorWriteLog(TAG, NULL));
1952
1953 sleep(2);
1954
1955 int count = 0;
1956
1957 for (;;) {
1958 log_msg log_msg;
1959 if (android_logger_list_read(logger_list, &log_msg) <= 0) {
1960 break;
1961 }
1962
1963 char *eventData = log_msg.msg();
1964
1965 // Tag
1966 int tag = get4LE(eventData);
1967 eventData += 4;
1968
1969 if (tag == TAG) {
1970 // This tag should not have been written because the data was null
1971 count++;
1972 break;
1973 }
1974 }
1975
1976 EXPECT_EQ(0, count);
1977
1978 android_logger_list_close(logger_list);
1979}
Mark Salyzynbd1ad042016-02-17 16:08:13 -08001980
1981static int is_real_element(int type) {
1982 return ((type == EVENT_TYPE_INT) ||
1983 (type == EVENT_TYPE_LONG) ||
1984 (type == EVENT_TYPE_STRING) ||
1985 (type == EVENT_TYPE_FLOAT));
1986}
1987
1988int android_log_buffer_to_string(const char *msg, size_t len,
1989 char *strOut, size_t strOutLen) {
1990 android_log_context context = create_android_log_parser(msg, len);
1991 android_log_list_element elem;
1992 bool overflow = false;
1993 /* Reserve 1 byte for null terminator. */
1994 size_t origStrOutLen = strOutLen--;
1995
1996 if (!context) {
1997 return -EBADF;
1998 }
1999
2000 memset(&elem, 0, sizeof(elem));
2001
2002 size_t outCount;
2003
2004 do {
2005 elem = android_log_read_next(context);
2006 switch ((int)elem.type) {
2007 case EVENT_TYPE_LIST:
2008 if (strOutLen == 0) {
2009 overflow = true;
2010 } else {
2011 *strOut++ = '[';
2012 strOutLen--;
2013 }
2014 break;
2015
2016 case EVENT_TYPE_LIST_STOP:
2017 if (strOutLen == 0) {
2018 overflow = true;
2019 } else {
2020 *strOut++ = ']';
2021 strOutLen--;
2022 }
2023 break;
2024
2025 case EVENT_TYPE_INT:
2026 /*
2027 * snprintf also requires room for the null terminator, which
2028 * we don't care about but we have allocated enough room for
2029 * that
2030 */
2031 outCount = snprintf(strOut, strOutLen + 1,
2032 "%" PRId32, elem.data.int32);
2033 if (outCount <= strOutLen) {
2034 strOut += outCount;
2035 strOutLen -= outCount;
2036 } else {
2037 overflow = true;
2038 }
2039 break;
2040
2041 case EVENT_TYPE_LONG:
2042 /*
2043 * snprintf also requires room for the null terminator, which
2044 * we don't care about but we have allocated enough room for
2045 * that
2046 */
2047 outCount = snprintf(strOut, strOutLen + 1,
2048 "%" PRId64, elem.data.int64);
2049 if (outCount <= strOutLen) {
2050 strOut += outCount;
2051 strOutLen -= outCount;
2052 } else {
2053 overflow = true;
2054 }
2055 break;
2056
2057 case EVENT_TYPE_FLOAT:
2058 /*
2059 * snprintf also requires room for the null terminator, which
2060 * we don't care about but we have allocated enough room for
2061 * that
2062 */
2063 outCount = snprintf(strOut, strOutLen + 1, "%f", elem.data.float32);
2064 if (outCount <= strOutLen) {
2065 strOut += outCount;
2066 strOutLen -= outCount;
2067 } else {
2068 overflow = true;
2069 }
2070 break;
2071
2072 default:
2073 elem.complete = true;
2074 break;
2075
2076 case EVENT_TYPE_UNKNOWN:
2077#if 0 // Ideal purity in the test, we want to complain about UNKNOWN showing up
2078 if (elem.complete) {
2079 break;
2080 }
2081#endif
2082 elem.data.string = const_cast<char *>("<unknown>");
2083 elem.len = strlen(elem.data.string);
2084 /* FALLTHRU */
2085 case EVENT_TYPE_STRING:
2086 if (elem.len <= strOutLen) {
2087 memcpy(strOut, elem.data.string, elem.len);
2088 strOut += elem.len;
2089 strOutLen -= elem.len;
2090 } else if (strOutLen > 0) {
2091 /* copy what we can */
2092 memcpy(strOut, elem.data.string, strOutLen);
2093 strOut += strOutLen;
2094 strOutLen = 0;
2095 overflow = true;
2096 }
2097 break;
2098 }
2099
2100 if (elem.complete) {
2101 break;
2102 }
2103 /* Determine whether to put a comma or not. */
2104 if (!overflow && (is_real_element(elem.type) ||
2105 (elem.type == EVENT_TYPE_LIST_STOP))) {
2106 android_log_list_element next = android_log_peek_next(context);
2107 if (!next.complete && (is_real_element(next.type) ||
2108 (next.type == EVENT_TYPE_LIST))) {
2109 if (strOutLen == 0) {
2110 overflow = true;
2111 } else {
2112 *strOut++ = ',';
2113 strOutLen--;
2114 }
2115 }
2116 }
2117 } while ((elem.type != EVENT_TYPE_UNKNOWN) && !overflow && !elem.complete);
2118
2119 android_log_destroy(&context);
2120
2121 if (overflow) {
2122 if (strOutLen < origStrOutLen) {
2123 /* leave an indicator */
2124 *(strOut-1) = '!';
2125 } else {
2126 /* nothing was written at all */
2127 *strOut++ = '!';
2128 }
2129 }
2130 *strOut++ = '\0';
2131
2132 if ((elem.type == EVENT_TYPE_UNKNOWN) && !elem.complete) {
2133 fprintf(stderr, "Binary log entry conversion failed\n");
2134 return -EINVAL;
2135 }
2136
2137 return 0;
2138}
2139
2140static const char *event_test_int32(uint32_t tag, size_t &expected_len) {
2141 android_log_context ctx;
2142
2143 EXPECT_TRUE(NULL != (ctx = create_android_logger(tag)));
2144 if (!ctx) {
2145 return NULL;
2146 }
2147 EXPECT_LE(0, android_log_write_int32(ctx, 0x40302010));
2148 EXPECT_LE(0, android_log_write_list(ctx, LOG_ID_EVENTS));
2149 EXPECT_LE(0, android_log_destroy(&ctx));
2150 EXPECT_TRUE(NULL == ctx);
2151
2152 expected_len = sizeof(uint32_t) +
2153 sizeof(uint8_t) + sizeof(uint32_t);
2154
2155 return "1076895760";
2156}
2157
2158static const char *event_test_int64(uint32_t tag, size_t &expected_len) {
2159 android_log_context ctx;
2160
2161 EXPECT_TRUE(NULL != (ctx = create_android_logger(tag)));
2162 if (!ctx) {
2163 return NULL;
2164 }
2165 EXPECT_LE(0, android_log_write_int64(ctx, 0x8070605040302010));
2166 EXPECT_LE(0, android_log_write_list(ctx, LOG_ID_EVENTS));
2167 EXPECT_LE(0, android_log_destroy(&ctx));
2168 EXPECT_TRUE(NULL == ctx);
2169
2170 expected_len = sizeof(uint32_t) +
2171 sizeof(uint8_t) + sizeof(uint64_t);
2172
2173 return "-9191740941672636400";
2174}
2175
2176static const char *event_test_list_int64(uint32_t tag, size_t &expected_len) {
2177 android_log_context ctx;
2178
2179 EXPECT_TRUE(NULL != (ctx = create_android_logger(tag)));
2180 if (!ctx) {
2181 return NULL;
2182 }
2183 EXPECT_LE(0, android_log_write_list_begin(ctx));
2184 EXPECT_LE(0, android_log_write_int64(ctx, 0x8070605040302010));
2185 EXPECT_LE(0, android_log_write_list_end(ctx));
2186 EXPECT_LE(0, android_log_write_list(ctx, LOG_ID_EVENTS));
2187 EXPECT_LE(0, android_log_destroy(&ctx));
2188 EXPECT_TRUE(NULL == ctx);
2189
2190 expected_len = sizeof(uint32_t) +
2191 sizeof(uint8_t) + sizeof(uint8_t) +
2192 sizeof(uint8_t) + sizeof(uint64_t);
2193
2194 return "[-9191740941672636400]";
2195}
2196
2197static const char *event_test_simple_automagic_list(uint32_t tag, size_t &expected_len) {
2198 android_log_context ctx;
2199
2200 EXPECT_TRUE(NULL != (ctx = create_android_logger(tag)));
2201 if (!ctx) {
2202 return NULL;
2203 }
2204 // The convenience API where we allow a simple list to be
2205 // created without explicit begin or end calls.
2206 EXPECT_LE(0, android_log_write_int32(ctx, 0x40302010));
2207 EXPECT_LE(0, android_log_write_int64(ctx, 0x8070605040302010));
2208 EXPECT_LE(0, android_log_write_list(ctx, LOG_ID_EVENTS));
2209 EXPECT_LE(0, android_log_destroy(&ctx));
2210 EXPECT_TRUE(NULL == ctx);
2211
2212 expected_len = sizeof(uint32_t) +
2213 sizeof(uint8_t) + sizeof(uint8_t) +
2214 sizeof(uint8_t) + sizeof(uint32_t) +
2215 sizeof(uint8_t) + sizeof(uint64_t);
2216
2217 return "[1076895760,-9191740941672636400]";
2218}
2219
2220static const char *event_test_list_empty(uint32_t tag, size_t &expected_len) {
2221 android_log_context ctx;
2222
2223 EXPECT_TRUE(NULL != (ctx = create_android_logger(tag)));
2224 if (!ctx) {
2225 return NULL;
2226 }
2227 EXPECT_LE(0, android_log_write_list_begin(ctx));
2228 EXPECT_LE(0, android_log_write_list_end(ctx));
2229 EXPECT_LE(0, android_log_write_list(ctx, LOG_ID_EVENTS));
2230 EXPECT_LE(0, android_log_destroy(&ctx));
2231 EXPECT_TRUE(NULL == ctx);
2232
2233 expected_len = sizeof(uint32_t) +
2234 sizeof(uint8_t) + sizeof(uint8_t);
2235
2236 return "[]";
2237}
2238
2239static const char *event_test_complex_nested_list(uint32_t tag, size_t &expected_len) {
2240 android_log_context ctx;
2241
2242 EXPECT_TRUE(NULL != (ctx = create_android_logger(tag)));
2243 if (!ctx) {
2244 return NULL;
2245 }
2246
2247 EXPECT_LE(0, android_log_write_list_begin(ctx)); // [
2248 EXPECT_LE(0, android_log_write_int32(ctx, 0x01020304));
2249 EXPECT_LE(0, android_log_write_int64(ctx, 0x0102030405060708));
2250 EXPECT_LE(0, android_log_write_string8(ctx, "Hello World"));
2251 EXPECT_LE(0, android_log_write_list_begin(ctx)); // [
2252 EXPECT_LE(0, android_log_write_int32(ctx, 1));
2253 EXPECT_LE(0, android_log_write_int32(ctx, 2));
2254 EXPECT_LE(0, android_log_write_int32(ctx, 3));
2255 EXPECT_LE(0, android_log_write_int32(ctx, 4));
2256 EXPECT_LE(0, android_log_write_list_end(ctx)); // ]
2257 EXPECT_LE(0, android_log_write_float32(ctx, 1.0102030405060708));
2258 EXPECT_LE(0, android_log_write_list_end(ctx)); // ]
2259
2260 //
2261 // This one checks for the automagic list creation because a list
2262 // begin and end was missing for it! This is actually an <oops> corner
2263 // case, and not the behavior we morally support. The automagic API is to
2264 // allow for a simple case of a series of objects in a single list. e.g.
2265 // int32,int32,int32,string -> [int32,int32,int32,string]
2266 //
2267 EXPECT_LE(0, android_log_write_string8(ctx, "dlroW olleH"));
2268
2269 EXPECT_LE(0, android_log_write_list(ctx, LOG_ID_EVENTS));
2270 EXPECT_LE(0, android_log_destroy(&ctx));
2271 EXPECT_TRUE(NULL == ctx);
2272
2273 expected_len = sizeof(uint32_t) +
2274 sizeof(uint8_t) + sizeof(uint8_t) +
2275 sizeof(uint8_t) + sizeof(uint8_t) +
2276 sizeof(uint8_t) + sizeof(uint32_t) +
2277 sizeof(uint8_t) + sizeof(uint64_t) +
2278 sizeof(uint8_t) + sizeof(uint32_t) +
2279 sizeof("Hello World") - 1 +
2280 sizeof(uint8_t) + sizeof(uint8_t) +
2281 4 * (sizeof(uint8_t) + sizeof(uint32_t)) +
2282 sizeof(uint8_t) + sizeof(uint32_t) +
2283 sizeof(uint8_t) + sizeof(uint32_t) +
2284 sizeof("dlroW olleH") - 1;
2285
2286 return "[[16909060,72623859790382856,Hello World,[1,2,3,4],1.010203],dlroW olleH]";
2287}
2288
2289static const char *event_test_7_level_prefix(uint32_t tag, size_t &expected_len) {
2290 android_log_context ctx;
2291
2292 EXPECT_TRUE(NULL != (ctx = create_android_logger(tag)));
2293 if (!ctx) {
2294 return NULL;
2295 }
2296 EXPECT_LE(0, android_log_write_list_begin(ctx));
2297 EXPECT_LE(0, android_log_write_list_begin(ctx));
2298 EXPECT_LE(0, android_log_write_list_begin(ctx));
2299 EXPECT_LE(0, android_log_write_list_begin(ctx));
2300 EXPECT_LE(0, android_log_write_list_begin(ctx));
2301 EXPECT_LE(0, android_log_write_list_begin(ctx));
2302 EXPECT_LE(0, android_log_write_list_begin(ctx));
2303 EXPECT_LE(0, android_log_write_int32(ctx, 1));
2304 EXPECT_LE(0, android_log_write_list_end(ctx));
2305 EXPECT_LE(0, android_log_write_int32(ctx, 2));
2306 EXPECT_LE(0, android_log_write_list_end(ctx));
2307 EXPECT_LE(0, android_log_write_int32(ctx, 3));
2308 EXPECT_LE(0, android_log_write_list_end(ctx));
2309 EXPECT_LE(0, android_log_write_int32(ctx, 4));
2310 EXPECT_LE(0, android_log_write_list_end(ctx));
2311 EXPECT_LE(0, android_log_write_int32(ctx, 5));
2312 EXPECT_LE(0, android_log_write_list_end(ctx));
2313 EXPECT_LE(0, android_log_write_int32(ctx, 6));
2314 EXPECT_LE(0, android_log_write_list_end(ctx));
2315 EXPECT_LE(0, android_log_write_int32(ctx, 7));
2316 EXPECT_LE(0, android_log_write_list_end(ctx));
2317 EXPECT_LE(0, android_log_write_list(ctx, LOG_ID_EVENTS));
2318 EXPECT_LE(0, android_log_destroy(&ctx));
2319 EXPECT_TRUE(NULL == ctx);
2320
2321 expected_len = sizeof(uint32_t) + 7 *
2322 (sizeof(uint8_t) + sizeof(uint8_t) + sizeof(uint8_t) + sizeof(uint32_t));
2323
2324 return "[[[[[[[1],2],3],4],5],6],7]";
2325}
2326
2327static const char *event_test_7_level_suffix(uint32_t tag, size_t &expected_len) {
2328 android_log_context ctx;
2329
2330 EXPECT_TRUE(NULL != (ctx = create_android_logger(tag)));
2331 if (!ctx) {
2332 return NULL;
2333 }
2334 EXPECT_LE(0, android_log_write_list_begin(ctx));
2335 EXPECT_LE(0, android_log_write_int32(ctx, 1));
2336 EXPECT_LE(0, android_log_write_list_begin(ctx));
2337 EXPECT_LE(0, android_log_write_int32(ctx, 2));
2338 EXPECT_LE(0, android_log_write_list_begin(ctx));
2339 EXPECT_LE(0, android_log_write_int32(ctx, 3));
2340 EXPECT_LE(0, android_log_write_list_begin(ctx));
2341 EXPECT_LE(0, android_log_write_int32(ctx, 4));
2342 EXPECT_LE(0, android_log_write_list_begin(ctx));
2343 EXPECT_LE(0, android_log_write_int32(ctx, 5));
2344 EXPECT_LE(0, android_log_write_list_begin(ctx));
2345 EXPECT_LE(0, android_log_write_int32(ctx, 6));
2346 EXPECT_LE(0, android_log_write_list_end(ctx));
2347 EXPECT_LE(0, android_log_write_list_end(ctx));
2348 EXPECT_LE(0, android_log_write_list_end(ctx));
2349 EXPECT_LE(0, android_log_write_list_end(ctx));
2350 EXPECT_LE(0, android_log_write_list_end(ctx));
2351 EXPECT_LE(0, android_log_write_list_end(ctx));
2352 EXPECT_LE(0, android_log_write_list(ctx, LOG_ID_EVENTS));
2353 EXPECT_LE(0, android_log_destroy(&ctx));
2354 EXPECT_TRUE(NULL == ctx);
2355
2356 expected_len = sizeof(uint32_t) + 6 *
2357 (sizeof(uint8_t) + sizeof(uint8_t) + sizeof(uint8_t) + sizeof(uint32_t));
2358
2359 return "[1,[2,[3,[4,[5,[6]]]]]]";
2360}
2361
Mark Salyzyn5cecedc2016-02-25 09:02:09 -08002362static const char *event_test_android_log_error_write(uint32_t tag, size_t &expected_len) {
2363 EXPECT_LE(0, __android_log_error_write(tag, "Hello World", 42, "dlroW olleH", 11));
2364
2365 expected_len = sizeof(uint32_t) +
2366 sizeof(uint8_t) + sizeof(uint8_t) +
2367 sizeof(uint8_t) + sizeof(uint32_t) + sizeof("Hello World") - 1 +
2368 sizeof(uint8_t) + sizeof(uint32_t) +
2369 sizeof(uint8_t) + sizeof(uint32_t) + sizeof("dlroW olleH") - 1;
2370
2371 return "[Hello World,42,dlroW olleH]";
2372}
2373
2374static const char *event_test_android_log_error_write_null(uint32_t tag, size_t &expected_len) {
2375 EXPECT_LE(0, __android_log_error_write(tag, "Hello World", 42, NULL, 0));
2376
2377 expected_len = sizeof(uint32_t) +
2378 sizeof(uint8_t) + sizeof(uint8_t) +
2379 sizeof(uint8_t) + sizeof(uint32_t) + sizeof("Hello World") - 1 +
2380 sizeof(uint8_t) + sizeof(uint32_t) +
2381 sizeof(uint8_t) + sizeof(uint32_t) + sizeof("") - 1;
2382
2383 return "[Hello World,42,]";
2384}
2385
Mark Salyzynbd1ad042016-02-17 16:08:13 -08002386// make sure all user buffers are flushed
2387static void print_barrier() {
2388 std::cout.flush();
2389 fflush(stdout);
2390 std::cerr.flush();
2391 fflush(stderr); // everything else is paranoia ...
2392}
2393
2394static void create_android_logger(const char *(*fn)(uint32_t tag, size_t &expected_len)) {
2395 struct logger_list *logger_list;
2396
2397 pid_t pid = getpid();
2398
2399 ASSERT_TRUE(NULL != (logger_list = android_logger_list_open(
2400 LOG_ID_EVENTS, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 1000, pid)));
2401
2402 log_time ts(android_log_clockid());
2403
2404 size_t expected_len;
2405 const char *expected_string = (*fn)(1005, expected_len);
2406
2407 if (!expected_string) {
2408 android_logger_list_close(logger_list);
2409 return;
2410 }
2411
2412 usleep(1000000);
2413
2414 int count = 0;
2415
2416 for (;;) {
2417 log_msg log_msg;
2418 if (android_logger_list_read(logger_list, &log_msg) <= 0) {
2419 break;
2420 }
2421
2422 ASSERT_EQ(log_msg.entry.pid, pid);
2423
2424 if ((log_msg.entry.sec < (ts.tv_sec - 1))
2425 || ((ts.tv_sec + 1) < log_msg.entry.sec)
2426 || ((size_t)log_msg.entry.len != expected_len)
2427 || (log_msg.id() != LOG_ID_EVENTS)) {
2428 continue;
2429 }
2430
2431 char *eventData = log_msg.msg();
2432
2433 ++count;
2434
2435 AndroidLogFormat *logformat = android_log_format_new();
2436 EXPECT_TRUE(NULL != logformat);
2437 AndroidLogEntry entry;
2438 char msgBuf[1024];
2439 int processBinaryLogBuffer = android_log_processBinaryLogBuffer(
2440 &log_msg.entry_v1, &entry, NULL, msgBuf, sizeof(msgBuf));
2441 EXPECT_EQ(0, processBinaryLogBuffer);
2442 if (processBinaryLogBuffer == 0) {
2443 print_barrier();
2444 int printLogLine = android_log_printLogLine(
2445 logformat, fileno(stderr), &entry);
2446 print_barrier();
2447 EXPECT_EQ(20 + (int)strlen(expected_string), printLogLine);
2448 }
2449 android_log_format_free(logformat);
2450
2451 // test buffer reading API
2452 snprintf(msgBuf, sizeof(msgBuf), "I/[%d]", get4LE(eventData));
2453 print_barrier();
2454 fprintf(stderr, "%-10s(%5u): ", msgBuf, pid);
2455 memset(msgBuf, 0, sizeof(msgBuf));
2456 int buffer_to_string = android_log_buffer_to_string(
2457 eventData + sizeof(uint32_t),
2458 log_msg.entry.len - sizeof(uint32_t),
2459 msgBuf, sizeof(msgBuf));
2460 fprintf(stderr, "%s\n", msgBuf);
2461 print_barrier();
2462 EXPECT_EQ(0, buffer_to_string);
2463 EXPECT_EQ(strlen(expected_string), strlen(msgBuf));
2464 EXPECT_EQ(0, strcmp(expected_string, msgBuf));
2465 }
2466
2467 EXPECT_EQ(1, count);
2468
2469 android_logger_list_close(logger_list);
2470}
2471
2472TEST(liblog, create_android_logger_int32) {
2473 create_android_logger(event_test_int32);
2474}
2475
2476TEST(liblog, create_android_logger_int64) {
2477 create_android_logger(event_test_int64);
2478}
2479
2480TEST(liblog, create_android_logger_list_int64) {
2481 create_android_logger(event_test_list_int64);
2482}
2483
2484TEST(liblog, create_android_logger_simple_automagic_list) {
2485 create_android_logger(event_test_simple_automagic_list);
2486}
2487
2488TEST(liblog, create_android_logger_list_empty) {
2489 create_android_logger(event_test_list_empty);
2490}
2491
2492TEST(liblog, create_android_logger_complex_nested_list) {
2493 create_android_logger(event_test_complex_nested_list);
2494}
2495
2496TEST(liblog, create_android_logger_7_level_prefix) {
2497 create_android_logger(event_test_7_level_prefix);
2498}
2499
2500TEST(liblog, create_android_logger_7_level_suffix) {
2501 create_android_logger(event_test_7_level_suffix);
2502}
2503
Mark Salyzyn5cecedc2016-02-25 09:02:09 -08002504TEST(liblog, create_android_logger_android_log_error_write) {
2505 create_android_logger(event_test_android_log_error_write);
2506}
2507
2508TEST(liblog, create_android_logger_android_log_error_write_null) {
2509 create_android_logger(event_test_android_log_error_write_null);
2510}
2511
Mark Salyzynbd1ad042016-02-17 16:08:13 -08002512TEST(liblog, create_android_logger_overflow) {
2513 android_log_context ctx;
2514
2515 EXPECT_TRUE(NULL != (ctx = create_android_logger(1005)));
2516 if (ctx) {
2517 for (size_t i = 0; i < ANDROID_MAX_LIST_NEST_DEPTH; ++i) {
2518 EXPECT_LE(0, android_log_write_list_begin(ctx));
2519 }
2520 EXPECT_GT(0, android_log_write_list_begin(ctx));
2521 /* One more for good measure, must be permanently unhappy */
2522 EXPECT_GT(0, android_log_write_list_begin(ctx));
2523 EXPECT_LE(0, android_log_destroy(&ctx));
2524 EXPECT_TRUE(NULL == ctx);
2525 }
2526
2527 ASSERT_TRUE(NULL != (ctx = create_android_logger(1005)));
2528 for (size_t i = 0; i < ANDROID_MAX_LIST_NEST_DEPTH; ++i) {
2529 EXPECT_LE(0, android_log_write_list_begin(ctx));
2530 EXPECT_LE(0, android_log_write_int32(ctx, i));
2531 }
2532 EXPECT_GT(0, android_log_write_list_begin(ctx));
2533 /* One more for good measure, must be permanently unhappy */
2534 EXPECT_GT(0, android_log_write_list_begin(ctx));
2535 EXPECT_LE(0, android_log_destroy(&ctx));
2536 ASSERT_TRUE(NULL == ctx);
2537}
Mark Salyzynd4b061b2016-03-10 09:50:08 -08002538
2539static const char __pmsg_file[] =
2540 "/data/william-shakespeare/MuchAdoAboutNothing.txt";
2541
2542TEST(liblog, __android_log_pmsg_file_write) {
2543 EXPECT_LT(0, __android_log_pmsg_file_write(
2544 LOG_ID_CRASH, ANDROID_LOG_VERBOSE,
2545 __pmsg_file, max_payload_buf, sizeof(max_payload_buf)));
Mark Salyzyn864e8e82016-03-14 14:15:50 -07002546 fprintf(stderr, "Reboot, ensure file %s matches\n"
2547 "with liblog.__android_log_msg_file_read test\n",
2548 __pmsg_file);
2549}
2550
2551ssize_t __pmsg_fn(log_id_t logId, char prio, const char *filename,
2552 const char *buf, size_t len, void *arg) {
2553 EXPECT_TRUE(NULL == arg);
2554 EXPECT_EQ(LOG_ID_CRASH, logId);
2555 EXPECT_EQ(ANDROID_LOG_VERBOSE, prio);
2556 EXPECT_FALSE(NULL == strstr(__pmsg_file, filename));
2557 EXPECT_EQ(len, sizeof(max_payload_buf));
2558 EXPECT_EQ(0, strcmp(max_payload_buf, buf));
2559
2560 ++signaled;
2561 if ((len != sizeof(max_payload_buf)) ||
2562 strcmp(max_payload_buf, buf)) {
2563 fprintf(stderr, "comparison fails on content \"%s\"\n", buf);
2564 }
2565 return !arg ||
2566 (LOG_ID_CRASH != logId) ||
2567 (ANDROID_LOG_VERBOSE != prio) ||
2568 !strstr(__pmsg_file, filename) ||
2569 (len != sizeof(max_payload_buf)) ||
2570 !!strcmp(max_payload_buf, buf) ? -ENOEXEC : 1;
2571}
2572
2573TEST(liblog, __android_log_pmsg_file_read) {
2574 signaled = 0;
2575
2576 ssize_t ret = __android_log_pmsg_file_read(
2577 LOG_ID_CRASH, ANDROID_LOG_VERBOSE,
2578 __pmsg_file, __pmsg_fn, NULL);
2579
2580 if (ret == -ENOENT) {
2581 fprintf(stderr,
2582 "No pre-boot results of liblog.__android_log_mesg_file_write to "
2583 "compare with,\n"
2584 "false positive test result.\n");
2585 return;
2586 }
2587
2588 EXPECT_LT(0, ret);
2589 EXPECT_EQ(1U, signaled);
Mark Salyzynd4b061b2016-03-10 09:50:08 -08002590}