1 /*
2 * Copyright (C) 2013-2014 The Android Open Source Project
3 *
4 * Licensed under the Apache License, Version 2.0 (the "License");
5 * you may not use this file except in compliance with the License.
6 * You may obtain a copy of the License at
7 *
8 * http://www.apache.org/licenses/LICENSE-2.0
9 *
10 * Unless required by applicable law or agreed to in writing, software
11 * distributed under the License is distributed on an "AS IS" BASIS,
12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13 * See the License for the specific language governing permissions and
14 * limitations under the License.
15 */
16
17 #include <fcntl.h>
18 #include <inttypes.h>
19 #include <signal.h>
20 #include <string.h>
21
22 #include <cutils/properties.h>
23 #include <gtest/gtest.h>
24 #include <log/log.h>
25 #include <log/logger.h>
26 #include <log/log_read.h>
27 #include <log/logprint.h>
28
29 // enhanced version of LOG_FAILURE_RETRY to add support for EAGAIN and
30 // non-syscall libs. Since we are only using this in the emergency of
31 // a signal to stuff a terminating code into the logs, we will spin rather
32 // than try a usleep.
33 #define LOG_FAILURE_RETRY(exp) ({ \
34 typeof (exp) _rc; \
35 do { \
36 _rc = (exp); \
37 } while (((_rc == -1) \
38 && ((errno == EINTR) \
39 || (errno == EAGAIN))) \
40 || (_rc == -EINTR) \
41 || (_rc == -EAGAIN)); \
42 _rc; })
43
TEST(liblog,__android_log_buf_print)44 TEST(liblog, __android_log_buf_print) {
45 EXPECT_LT(0, __android_log_buf_print(LOG_ID_RADIO, ANDROID_LOG_INFO,
46 "TEST__android_log_buf_print",
47 "radio"));
48 usleep(1000);
49 EXPECT_LT(0, __android_log_buf_print(LOG_ID_SYSTEM, ANDROID_LOG_INFO,
50 "TEST__android_log_buf_print",
51 "system"));
52 usleep(1000);
53 EXPECT_LT(0, __android_log_buf_print(LOG_ID_MAIN, ANDROID_LOG_INFO,
54 "TEST__android_log_buf_print",
55 "main"));
56 usleep(1000);
57 }
58
TEST(liblog,__android_log_buf_write)59 TEST(liblog, __android_log_buf_write) {
60 EXPECT_LT(0, __android_log_buf_write(LOG_ID_RADIO, ANDROID_LOG_INFO,
61 "TEST__android_log_buf_write",
62 "radio"));
63 usleep(1000);
64 EXPECT_LT(0, __android_log_buf_write(LOG_ID_SYSTEM, ANDROID_LOG_INFO,
65 "TEST__android_log_buf_write",
66 "system"));
67 usleep(1000);
68 EXPECT_LT(0, __android_log_buf_write(LOG_ID_MAIN, ANDROID_LOG_INFO,
69 "TEST__android_log_buf_write",
70 "main"));
71 usleep(1000);
72 }
73
TEST(liblog,__android_log_btwrite)74 TEST(liblog, __android_log_btwrite) {
75 int intBuf = 0xDEADBEEF;
76 EXPECT_LT(0, __android_log_btwrite(0,
77 EVENT_TYPE_INT,
78 &intBuf, sizeof(intBuf)));
79 long long longBuf = 0xDEADBEEFA55A5AA5;
80 EXPECT_LT(0, __android_log_btwrite(0,
81 EVENT_TYPE_LONG,
82 &longBuf, sizeof(longBuf)));
83 usleep(1000);
84 char Buf[] = "\20\0\0\0DeAdBeEfA55a5aA5";
85 EXPECT_LT(0, __android_log_btwrite(0,
86 EVENT_TYPE_STRING,
87 Buf, sizeof(Buf) - 1));
88 usleep(1000);
89 }
90
ConcurrentPrintFn(void * arg)91 static void* ConcurrentPrintFn(void *arg) {
92 int ret = __android_log_buf_print(LOG_ID_MAIN, ANDROID_LOG_INFO,
93 "TEST__android_log_print", "Concurrent %" PRIuPTR,
94 reinterpret_cast<uintptr_t>(arg));
95 return reinterpret_cast<void*>(ret);
96 }
97
98 #define NUM_CONCURRENT 64
99 #define _concurrent_name(a,n) a##__concurrent##n
100 #define concurrent_name(a,n) _concurrent_name(a,n)
101
TEST(liblog,concurrent_name (__android_log_buf_print,NUM_CONCURRENT))102 TEST(liblog, concurrent_name(__android_log_buf_print, NUM_CONCURRENT)) {
103 pthread_t t[NUM_CONCURRENT];
104 int i;
105 for (i=0; i < NUM_CONCURRENT; i++) {
106 ASSERT_EQ(0, pthread_create(&t[i], NULL,
107 ConcurrentPrintFn,
108 reinterpret_cast<void *>(i)));
109 }
110 int ret = 0;
111 for (i=0; i < NUM_CONCURRENT; i++) {
112 void* result;
113 ASSERT_EQ(0, pthread_join(t[i], &result));
114 int this_result = reinterpret_cast<uintptr_t>(result);
115 if ((0 == ret) && (0 != this_result)) {
116 ret = this_result;
117 }
118 }
119 ASSERT_LT(0, ret);
120 }
121
TEST(liblog,__android_log_btwrite__android_logger_list_read)122 TEST(liblog, __android_log_btwrite__android_logger_list_read) {
123 struct logger_list *logger_list;
124
125 pid_t pid = getpid();
126
127 ASSERT_TRUE(NULL != (logger_list = android_logger_list_open(
128 LOG_ID_EVENTS, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 1000, pid)));
129
130 log_time ts(CLOCK_MONOTONIC);
131
132 ASSERT_LT(0, __android_log_btwrite(0, EVENT_TYPE_LONG, &ts, sizeof(ts)));
133 usleep(1000000);
134
135 int count = 0;
136
137 for (;;) {
138 log_msg log_msg;
139 if (android_logger_list_read(logger_list, &log_msg) <= 0) {
140 break;
141 }
142
143 ASSERT_EQ(log_msg.entry.pid, pid);
144
145 if ((log_msg.entry.len != (4 + 1 + 8))
146 || (log_msg.id() != LOG_ID_EVENTS)) {
147 continue;
148 }
149
150 char *eventData = log_msg.msg();
151
152 if (eventData[4] != EVENT_TYPE_LONG) {
153 continue;
154 }
155
156 log_time tx(eventData + 4 + 1);
157 if (ts == tx) {
158 ++count;
159 }
160 }
161
162 EXPECT_EQ(1, count);
163
164 android_logger_list_close(logger_list);
165 }
166
167 static unsigned signaled;
168 log_time signal_time;
169
caught_blocking(int)170 static void caught_blocking(int /*signum*/)
171 {
172 unsigned long long v = 0xDEADBEEFA55A0000ULL;
173
174 v += getpid() & 0xFFFF;
175
176 ++signaled;
177 if ((signal_time.tv_sec == 0) && (signal_time.tv_nsec == 0)) {
178 signal_time = log_time(CLOCK_MONOTONIC);
179 signal_time.tv_sec += 2;
180 }
181
182 LOG_FAILURE_RETRY(__android_log_btwrite(0, EVENT_TYPE_LONG, &v, sizeof(v)));
183 }
184
185 // Fill in current process user and system time in 10ms increments
get_ticks(unsigned long long * uticks,unsigned long long * sticks)186 static void get_ticks(unsigned long long *uticks, unsigned long long *sticks)
187 {
188 *uticks = *sticks = 0;
189
190 pid_t pid = getpid();
191
192 char buffer[512];
193 snprintf(buffer, sizeof(buffer), "/proc/%u/stat", pid);
194
195 FILE *fp = fopen(buffer, "r");
196 if (!fp) {
197 return;
198 }
199
200 char *cp = fgets(buffer, sizeof(buffer), fp);
201 fclose(fp);
202 if (!cp) {
203 return;
204 }
205
206 pid_t d;
207 char s[sizeof(buffer)];
208 char c;
209 long long ll;
210 unsigned long long ull;
211
212 if (15 != sscanf(buffer,
213 "%d %s %c %lld %lld %lld %lld %lld %llu %llu %llu %llu %llu %llu %llu ",
214 &d, s, &c, &ll, &ll, &ll, &ll, &ll, &ull, &ull, &ull, &ull, &ull,
215 uticks, sticks)) {
216 *uticks = *sticks = 0;
217 }
218 }
219
TEST(liblog,android_logger_list_read__cpu)220 TEST(liblog, android_logger_list_read__cpu) {
221 struct logger_list *logger_list;
222 unsigned long long v = 0xDEADBEEFA55A0000ULL;
223
224 pid_t pid = getpid();
225
226 v += pid & 0xFFFF;
227
228 ASSERT_TRUE(NULL != (logger_list = android_logger_list_open(
229 LOG_ID_EVENTS, ANDROID_LOG_RDONLY, 1000, pid)));
230
231 int count = 0;
232
233 int signals = 0;
234
235 unsigned long long uticks_start;
236 unsigned long long sticks_start;
237 get_ticks(&uticks_start, &sticks_start);
238
239 const unsigned alarm_time = 10;
240
241 memset(&signal_time, 0, sizeof(signal_time));
242
243 signal(SIGALRM, caught_blocking);
244 alarm(alarm_time);
245
246 signaled = 0;
247
248 do {
249 log_msg log_msg;
250 if (android_logger_list_read(logger_list, &log_msg) <= 0) {
251 break;
252 }
253
254 alarm(alarm_time);
255
256 ++count;
257
258 ASSERT_EQ(log_msg.entry.pid, pid);
259
260 if ((log_msg.entry.len != (4 + 1 + 8))
261 || (log_msg.id() != LOG_ID_EVENTS)) {
262 continue;
263 }
264
265 char *eventData = log_msg.msg();
266
267 if (eventData[4] != EVENT_TYPE_LONG) {
268 continue;
269 }
270
271 unsigned long long l = eventData[4 + 1 + 0] & 0xFF;
272 l |= (unsigned long long) (eventData[4 + 1 + 1] & 0xFF) << 8;
273 l |= (unsigned long long) (eventData[4 + 1 + 2] & 0xFF) << 16;
274 l |= (unsigned long long) (eventData[4 + 1 + 3] & 0xFF) << 24;
275 l |= (unsigned long long) (eventData[4 + 1 + 4] & 0xFF) << 32;
276 l |= (unsigned long long) (eventData[4 + 1 + 5] & 0xFF) << 40;
277 l |= (unsigned long long) (eventData[4 + 1 + 6] & 0xFF) << 48;
278 l |= (unsigned long long) (eventData[4 + 1 + 7] & 0xFF) << 56;
279
280 if (l == v) {
281 ++signals;
282 break;
283 }
284 } while (!signaled || (log_time(CLOCK_MONOTONIC) < signal_time));
285 alarm(0);
286 signal(SIGALRM, SIG_DFL);
287
288 EXPECT_LT(1, count);
289
290 EXPECT_EQ(1, signals);
291
292 android_logger_list_close(logger_list);
293
294 unsigned long long uticks_end;
295 unsigned long long sticks_end;
296 get_ticks(&uticks_end, &sticks_end);
297
298 // Less than 1% in either user or system time, or both
299 const unsigned long long one_percent_ticks = alarm_time;
300 unsigned long long user_ticks = uticks_end - uticks_start;
301 unsigned long long system_ticks = sticks_end - sticks_start;
302 EXPECT_GT(one_percent_ticks, user_ticks);
303 EXPECT_GT(one_percent_ticks, system_ticks);
304 EXPECT_GT(one_percent_ticks, user_ticks + system_ticks);
305 }
306
307 static const char max_payload_tag[] = "TEST_max_payload_XXXX";
308 static const char max_payload_buf[LOGGER_ENTRY_MAX_PAYLOAD
309 - sizeof(max_payload_tag) - 1] = "LEONATO\n\
310 I learn in this letter that Don Peter of Arragon\n\
311 comes this night to Messina\n\
312 MESSENGER\n\
313 He is very near by this: he was not three leagues off\n\
314 when I left him\n\
315 LEONATO\n\
316 How many gentlemen have you lost in this action?\n\
317 MESSENGER\n\
318 But few of any sort, and none of name\n\
319 LEONATO\n\
320 A victory is twice itself when the achiever brings\n\
321 home full numbers. I find here that Don Peter hath\n\
322 bestowed much honour on a young Florentine called Claudio\n\
323 MESSENGER\n\
324 Much deserved on his part and equally remembered by\n\
325 Don Pedro: he hath borne himself beyond the\n\
326 promise of his age, doing, in the figure of a lamb,\n\
327 the feats of a lion: he hath indeed better\n\
328 bettered expectation than you must expect of me to\n\
329 tell you how\n\
330 LEONATO\n\
331 He hath an uncle here in Messina will be very much\n\
332 glad of it.\n\
333 MESSENGER\n\
334 I have already delivered him letters, and there\n\
335 appears much joy in him; even so much that joy could\n\
336 not show itself modest enough without a badge of\n\
337 bitterness.\n\
338 LEONATO\n\
339 Did he break out into tears?\n\
340 MESSENGER\n\
341 In great measure.\n\
342 LEONATO\n\
343 A kind overflow of kindness: there are no faces\n\
344 truer than those that are so washed. How much\n\
345 better is it to weep at joy than to joy at weeping!\n\
346 BEATRICE\n\
347 I pray you, is Signior Mountanto returned from the\n\
348 wars or no?\n\
349 MESSENGER\n\
350 I know none of that name, lady: there was none such\n\
351 in the army of any sort.\n\
352 LEONATO\n\
353 What is he that you ask for, niece?\n\
354 HERO\n\
355 My cousin means Signior Benedick of Padua.\n\
356 MESSENGER\n\
357 O, he's returned; and as pleasant as ever he was.\n\
358 BEATRICE\n\
359 He set up his bills here in Messina and challenged\n\
360 Cupid at the flight; and my uncle's fool, reading\n\
361 the challenge, subscribed for Cupid, and challenged\n\
362 him at the bird-bolt. I pray you, how many hath he\n\
363 killed and eaten in these wars? But how many hath\n\
364 he killed? for indeed I promised to eat all of his killing.\n\
365 LEONATO\n\
366 Faith, niece, you tax Signior Benedick too much;\n\
367 but he'll be meet with you, I doubt it not.\n\
368 MESSENGER\n\
369 He hath done good service, lady, in these wars.\n\
370 BEATRICE\n\
371 You had musty victual, and he hath holp to eat it:\n\
372 he is a very valiant trencherman; he hath an\n\
373 excellent stomach.\n\
374 MESSENGER\n\
375 And a good soldier too, lady.\n\
376 BEATRICE\n\
377 And a good soldier to a lady: but what is he to a lord?\n\
378 MESSENGER\n\
379 A lord to a lord, a man to a man; stuffed with all\n\
380 honourable virtues.\n\
381 BEATRICE\n\
382 It is so, indeed; he is no less than a stuffed man:\n\
383 but for the stuffing,--well, we are all mortal.\n\
384 LEONATO\n\
385 You must not, sir, mistake my niece. There is a\n\
386 kind of merry war betwixt Signior Benedick and her:\n\
387 they never meet but there's a skirmish of wit\n\
388 between them.\n\
389 BEATRICE\n\
390 Alas! he gets nothing by that. In our last\n\
391 conflict four of his five wits went halting off, and\n\
392 now is the whole man governed with one: so that if\n\
393 he have wit enough to keep himself warm, let him\n\
394 bear it for a difference between himself and his\n\
395 horse; for it is all the wealth that he hath left,\n\
396 to be known a reasonable creature. Who is his\n\
397 companion now? He hath every month a new sworn brother.\n\
398 MESSENGER\n\
399 Is't possible?\n\
400 BEATRICE\n\
401 Very easily possible: he wears his faith but as\n\
402 the fashion of his hat; it ever changes with the\n\
403 next block.\n\
404 MESSENGER\n\
405 I see, lady, the gentleman is not in your books.\n\
406 BEATRICE\n\
407 No; an he were, I would burn my study. But, I pray\n\
408 you, who is his companion? Is there no young\n\
409 squarer now that will make a voyage with him to the devil?\n\
410 MESSENGER\n\
411 He is most in the company of the right noble Claudio.\n\
412 BEATRICE\n\
413 O Lord, he will hang upon him like a disease: he\n\
414 is sooner caught than the pestilence, and the taker\n\
415 runs presently mad. God help the noble Claudio! if\n\
416 he have caught the Benedick, it will cost him a\n\
417 thousand pound ere a' be cured.\n\
418 MESSENGER\n\
419 I will hold friends with you, lady.\n\
420 BEATRICE\n\
421 Do, good friend.\n\
422 LEONATO\n\
423 You will never run mad, niece.\n\
424 BEATRICE\n\
425 No, not till a hot January.\n\
426 MESSENGER\n\
427 Don Pedro is approached.\n\
428 Enter DON PEDRO, DON JOHN, CLAUDIO, BENEDICK, and BALTHASAR\n\
429 \n\
430 DON PEDRO\n\
431 Good Signior Leonato, you are come to meet your\n\
432 trouble: the fashion of the world is to avoid\n\
433 cost, and you encounter it\n\
434 LEONATO\n\
435 Never came trouble to my house in the likeness";
436
TEST(liblog,max_payload)437 TEST(liblog, max_payload) {
438 pid_t pid = getpid();
439 char tag[sizeof(max_payload_tag)];
440 memcpy(tag, max_payload_tag, sizeof(tag));
441 snprintf(tag + sizeof(tag) - 5, 5, "%04X", pid & 0xFFFF);
442
443 LOG_FAILURE_RETRY(__android_log_buf_write(LOG_ID_SYSTEM, ANDROID_LOG_INFO,
444 tag, max_payload_buf));
445 sleep(2);
446
447 struct logger_list *logger_list;
448
449 ASSERT_TRUE(NULL != (logger_list = android_logger_list_open(
450 LOG_ID_SYSTEM, ANDROID_LOG_RDONLY, 100, 0)));
451
452 bool matches = false;
453 ssize_t max_len = 0;
454
455 for(;;) {
456 log_msg log_msg;
457 if (android_logger_list_read(logger_list, &log_msg) <= 0) {
458 break;
459 }
460
461 if ((log_msg.entry.pid != pid) || (log_msg.id() != LOG_ID_SYSTEM)) {
462 continue;
463 }
464
465 char *data = log_msg.msg() + 1;
466
467 if (strcmp(data, tag)) {
468 continue;
469 }
470
471 data += strlen(data) + 1;
472
473 const char *left = data;
474 const char *right = max_payload_buf;
475 while (*left && *right && (*left == *right)) {
476 ++left;
477 ++right;
478 }
479
480 if (max_len <= (left - data)) {
481 max_len = left - data + 1;
482 }
483
484 if (max_len > 512) {
485 matches = true;
486 break;
487 }
488 }
489
490 android_logger_list_close(logger_list);
491
492 EXPECT_EQ(true, matches);
493
494 EXPECT_LE(sizeof(max_payload_buf), static_cast<size_t>(max_len));
495 }
496
TEST(liblog,too_big_payload)497 TEST(liblog, too_big_payload) {
498 pid_t pid = getpid();
499 static const char big_payload_tag[] = "TEST_big_payload_XXXX";
500 char tag[sizeof(big_payload_tag)];
501 memcpy(tag, big_payload_tag, sizeof(tag));
502 snprintf(tag + sizeof(tag) - 5, 5, "%04X", pid & 0xFFFF);
503
504 std::string longString(3266519, 'x');
505
506 ssize_t ret = LOG_FAILURE_RETRY(__android_log_buf_write(LOG_ID_SYSTEM,
507 ANDROID_LOG_INFO, tag, longString.c_str()));
508
509 struct logger_list *logger_list;
510
511 ASSERT_TRUE(NULL != (logger_list = android_logger_list_open(
512 LOG_ID_SYSTEM, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 100, 0)));
513
514 ssize_t max_len = 0;
515
516 for(;;) {
517 log_msg log_msg;
518 if (android_logger_list_read(logger_list, &log_msg) <= 0) {
519 break;
520 }
521
522 if ((log_msg.entry.pid != pid) || (log_msg.id() != LOG_ID_SYSTEM)) {
523 continue;
524 }
525
526 char *data = log_msg.msg() + 1;
527
528 if (strcmp(data, tag)) {
529 continue;
530 }
531
532 data += strlen(data) + 1;
533
534 const char *left = data;
535 const char *right = longString.c_str();
536 while (*left && *right && (*left == *right)) {
537 ++left;
538 ++right;
539 }
540
541 if (max_len <= (left - data)) {
542 max_len = left - data + 1;
543 }
544 }
545
546 android_logger_list_close(logger_list);
547
548 EXPECT_LE(LOGGER_ENTRY_MAX_PAYLOAD - sizeof(big_payload_tag),
549 static_cast<size_t>(max_len));
550
551 EXPECT_EQ(ret, max_len + static_cast<ssize_t>(sizeof(big_payload_tag)));
552 }
553
TEST(liblog,dual_reader)554 TEST(liblog, dual_reader) {
555 struct logger_list *logger_list1;
556
557 // >25 messages due to liblog.__android_log_buf_print__concurrentXX above.
558 ASSERT_TRUE(NULL != (logger_list1 = android_logger_list_open(
559 LOG_ID_MAIN, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 25, 0)));
560
561 struct logger_list *logger_list2;
562
563 if (NULL == (logger_list2 = android_logger_list_open(
564 LOG_ID_MAIN, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 15, 0))) {
565 android_logger_list_close(logger_list1);
566 ASSERT_TRUE(NULL != logger_list2);
567 }
568
569 int count1 = 0;
570 bool done1 = false;
571 int count2 = 0;
572 bool done2 = false;
573
574 do {
575 log_msg log_msg;
576
577 if (!done1) {
578 if (android_logger_list_read(logger_list1, &log_msg) <= 0) {
579 done1 = true;
580 } else {
581 ++count1;
582 }
583 }
584
585 if (!done2) {
586 if (android_logger_list_read(logger_list2, &log_msg) <= 0) {
587 done2 = true;
588 } else {
589 ++count2;
590 }
591 }
592 } while ((!done1) || (!done2));
593
594 android_logger_list_close(logger_list1);
595 android_logger_list_close(logger_list2);
596
597 EXPECT_EQ(25, count1);
598 EXPECT_EQ(15, count2);
599 }
600
TEST(liblog,android_logger_get_)601 TEST(liblog, android_logger_get_) {
602 struct logger_list * logger_list = android_logger_list_alloc(ANDROID_LOG_WRONLY, 0, 0);
603
604 for(int i = LOG_ID_MIN; i < LOG_ID_MAX; ++i) {
605 log_id_t id = static_cast<log_id_t>(i);
606 const char *name = android_log_id_to_name(id);
607 if (id != android_name_to_log_id(name)) {
608 continue;
609 }
610 fprintf(stderr, "log buffer %s\r", name);
611 struct logger * logger;
612 EXPECT_TRUE(NULL != (logger = android_logger_open(logger_list, id)));
613 EXPECT_EQ(id, android_logger_get_id(logger));
614 /* crash buffer is allowed to be empty, that is actually healthy! */
615 if (android_logger_get_log_size(logger) || strcmp("crash", name)) {
616 EXPECT_LT(0, android_logger_get_log_size(logger));
617 }
618 EXPECT_LT(0, android_logger_get_log_readable_size(logger));
619 EXPECT_LT(0, android_logger_get_log_version(logger));
620 }
621
622 android_logger_list_close(logger_list);
623 }
624
checkPriForTag(AndroidLogFormat * p_format,const char * tag,android_LogPriority pri)625 static bool checkPriForTag(AndroidLogFormat *p_format, const char *tag, android_LogPriority pri) {
626 return android_log_shouldPrintLine(p_format, tag, pri)
627 && !android_log_shouldPrintLine(p_format, tag, (android_LogPriority)(pri - 1));
628 }
629
TEST(liblog,filterRule)630 TEST(liblog, filterRule) {
631 static const char tag[] = "random";
632
633 AndroidLogFormat *p_format = android_log_format_new();
634
635 android_log_addFilterRule(p_format,"*:i");
636
637 EXPECT_TRUE(checkPriForTag(p_format, tag, ANDROID_LOG_INFO));
638 EXPECT_TRUE(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) == 0);
639 android_log_addFilterRule(p_format, "*");
640 EXPECT_TRUE (checkPriForTag(p_format, tag, ANDROID_LOG_DEBUG));
641 EXPECT_TRUE(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) > 0);
642 android_log_addFilterRule(p_format, "*:v");
643 EXPECT_TRUE (checkPriForTag(p_format, tag, ANDROID_LOG_VERBOSE));
644 EXPECT_TRUE(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) > 0);
645 android_log_addFilterRule(p_format, "*:i");
646 EXPECT_TRUE (checkPriForTag(p_format, tag, ANDROID_LOG_INFO));
647 EXPECT_TRUE(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) == 0);
648
649 android_log_addFilterRule(p_format, tag);
650 EXPECT_TRUE (checkPriForTag(p_format, tag, ANDROID_LOG_VERBOSE));
651 EXPECT_TRUE(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) > 0);
652 android_log_addFilterRule(p_format, "random:v");
653 EXPECT_TRUE (checkPriForTag(p_format, tag, ANDROID_LOG_VERBOSE));
654 EXPECT_TRUE(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) > 0);
655 android_log_addFilterRule(p_format, "random:d");
656 EXPECT_TRUE (checkPriForTag(p_format, tag, ANDROID_LOG_DEBUG));
657 EXPECT_TRUE(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) > 0);
658 android_log_addFilterRule(p_format, "random:w");
659 EXPECT_TRUE (checkPriForTag(p_format, tag, ANDROID_LOG_WARN));
660 EXPECT_TRUE(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) == 0);
661
662 android_log_addFilterRule(p_format, "crap:*");
663 EXPECT_TRUE (checkPriForTag(p_format, "crap", ANDROID_LOG_VERBOSE));
664 EXPECT_TRUE(android_log_shouldPrintLine(p_format, "crap", ANDROID_LOG_VERBOSE) > 0);
665
666 // invalid expression
667 EXPECT_TRUE (android_log_addFilterRule(p_format, "random:z") < 0);
668 EXPECT_TRUE (checkPriForTag(p_format, tag, ANDROID_LOG_WARN));
669 EXPECT_TRUE(android_log_shouldPrintLine(p_format, tag, ANDROID_LOG_DEBUG) == 0);
670
671 // Issue #550946
672 EXPECT_TRUE(android_log_addFilterString(p_format, " ") == 0);
673 EXPECT_TRUE(checkPriForTag(p_format, tag, ANDROID_LOG_WARN));
674
675 // note trailing space
676 EXPECT_TRUE(android_log_addFilterString(p_format, "*:s random:d ") == 0);
677 EXPECT_TRUE(checkPriForTag(p_format, tag, ANDROID_LOG_DEBUG));
678
679 EXPECT_TRUE(android_log_addFilterString(p_format, "*:s random:z") < 0);
680
681 #if 0 // bitrot, seek update
682 char defaultBuffer[512];
683
684 android_log_formatLogLine(p_format,
685 defaultBuffer, sizeof(defaultBuffer), 0, ANDROID_LOG_ERROR, 123,
686 123, 123, tag, "nofile", strlen("Hello"), "Hello", NULL);
687
688 fprintf(stderr, "%s\n", defaultBuffer);
689 #endif
690
691 android_log_format_free(p_format);
692 }
693
TEST(liblog,is_loggable)694 TEST(liblog, is_loggable) {
695 static const char tag[] = "is_loggable";
696 static const char log_namespace[] = "persist.log.tag.";
697 static const size_t base_offset = 8; /* skip "persist." */
698 // sizeof("string") = strlen("string") + 1
699 char key[sizeof(log_namespace) + sizeof(tag) - 1];
700 char hold[4][PROP_VALUE_MAX];
701 static const struct {
702 int level;
703 char type;
704 } levels[] = {
705 { ANDROID_LOG_VERBOSE, 'v' },
706 { ANDROID_LOG_DEBUG , 'd' },
707 { ANDROID_LOG_INFO , 'i' },
708 { ANDROID_LOG_WARN , 'w' },
709 { ANDROID_LOG_ERROR , 'e' },
710 { ANDROID_LOG_FATAL , 'a' },
711 { -1 , 's' },
712 { -2 , 'g' }, // Illegal value, resort to default
713 };
714
715 // Set up initial test condition
716 memset(hold, 0, sizeof(hold));
717 snprintf(key, sizeof(key), "%s%s", log_namespace, tag);
718 property_get(key, hold[0], "");
719 property_set(key, "");
720 property_get(key + base_offset, hold[1], "");
721 property_set(key + base_offset, "");
722 strcpy(key, log_namespace);
723 key[sizeof(log_namespace) - 2] = '\0';
724 property_get(key, hold[2], "");
725 property_set(key, "");
726 property_get(key, hold[3], "");
727 property_set(key + base_offset, "");
728
729 // All combinations of level and defaults
730 for(size_t i = 0; i < (sizeof(levels) / sizeof(levels[0])); ++i) {
731 if (levels[i].level == -2) {
732 continue;
733 }
734 for(size_t j = 0; j < (sizeof(levels) / sizeof(levels[0])); ++j) {
735 if (levels[j].level == -2) {
736 continue;
737 }
738 fprintf(stderr, "i=%zu j=%zu\r", i, j);
739 if ((levels[i].level < levels[j].level)
740 || (levels[j].level == -1)) {
741 EXPECT_FALSE(__android_log_is_loggable(levels[i].level, tag,
742 levels[j].level));
743 } else {
744 EXPECT_TRUE(__android_log_is_loggable(levels[i].level, tag,
745 levels[j].level));
746 }
747 }
748 }
749
750 // All combinations of level and tag and global properties
751 for(size_t i = 0; i < (sizeof(levels) / sizeof(levels[0])); ++i) {
752 if (levels[i].level == -2) {
753 continue;
754 }
755 for(size_t j = 0; j < (sizeof(levels) / sizeof(levels[0])); ++j) {
756 char buf[2];
757 buf[0] = levels[j].type;
758 buf[1] = '\0';
759
760 snprintf(key, sizeof(key), "%s%s", log_namespace, tag);
761 fprintf(stderr, "i=%zu j=%zu property_set(\"%s\",\"%s\")\r",
762 i, j, key, buf);
763 property_set(key, buf);
764 if ((levels[i].level < levels[j].level)
765 || (levels[j].level == -1)
766 || ((levels[i].level < ANDROID_LOG_DEBUG)
767 && (levels[j].level == -2))) {
768 EXPECT_FALSE(__android_log_is_loggable(levels[i].level, tag,
769 ANDROID_LOG_DEBUG));
770 } else {
771 EXPECT_TRUE(__android_log_is_loggable(levels[i].level, tag,
772 ANDROID_LOG_DEBUG));
773 }
774 property_set(key, "");
775
776 fprintf(stderr, "i=%zu j=%zu property_set(\"%s\",\"%s\")\r",
777 i, j, key + base_offset, buf);
778 property_set(key + base_offset, buf);
779 if ((levels[i].level < levels[j].level)
780 || (levels[j].level == -1)
781 || ((levels[i].level < ANDROID_LOG_DEBUG)
782 && (levels[j].level == -2))) {
783 EXPECT_FALSE(__android_log_is_loggable(levels[i].level, tag,
784 ANDROID_LOG_DEBUG));
785 } else {
786 EXPECT_TRUE(__android_log_is_loggable(levels[i].level, tag,
787 ANDROID_LOG_DEBUG));
788 }
789 property_set(key + base_offset, "");
790
791 strcpy(key, log_namespace);
792 key[sizeof(log_namespace) - 2] = '\0';
793 fprintf(stderr, "i=%zu j=%zu property_set(\"%s\",\"%s\")\r",
794 i, j, key, buf);
795 property_set(key, buf);
796 if ((levels[i].level < levels[j].level)
797 || (levels[j].level == -1)
798 || ((levels[i].level < ANDROID_LOG_DEBUG)
799 && (levels[j].level == -2))) {
800 EXPECT_FALSE(__android_log_is_loggable(levels[i].level, tag,
801 ANDROID_LOG_DEBUG));
802 } else {
803 EXPECT_TRUE(__android_log_is_loggable(levels[i].level, tag,
804 ANDROID_LOG_DEBUG));
805 }
806 property_set(key, "");
807
808 fprintf(stderr, "i=%zu j=%zu property_set(\"%s\",\"%s\")\r",
809 i, j, key + base_offset, buf);
810 property_set(key + base_offset, buf);
811 if ((levels[i].level < levels[j].level)
812 || (levels[j].level == -1)
813 || ((levels[i].level < ANDROID_LOG_DEBUG)
814 && (levels[j].level == -2))) {
815 EXPECT_FALSE(__android_log_is_loggable(levels[i].level, tag,
816 ANDROID_LOG_DEBUG));
817 } else {
818 EXPECT_TRUE(__android_log_is_loggable(levels[i].level, tag,
819 ANDROID_LOG_DEBUG));
820 }
821 property_set(key + base_offset, "");
822 }
823 }
824
825 // All combinations of level and tag properties, but with global set to INFO
826 strcpy(key, log_namespace);
827 key[sizeof(log_namespace) - 2] = '\0';
828 property_set(key, "I");
829 snprintf(key, sizeof(key), "%s%s", log_namespace, tag);
830 for(size_t i = 0; i < (sizeof(levels) / sizeof(levels[0])); ++i) {
831 if (levels[i].level == -2) {
832 continue;
833 }
834 for(size_t j = 0; j < (sizeof(levels) / sizeof(levels[0])); ++j) {
835 char buf[2];
836 buf[0] = levels[j].type;
837 buf[1] = '\0';
838
839 fprintf(stderr, "i=%zu j=%zu property_set(\"%s\",\"%s\")\r",
840 i, j, key, buf);
841 property_set(key, buf);
842 if ((levels[i].level < levels[j].level)
843 || (levels[j].level == -1)
844 || ((levels[i].level < ANDROID_LOG_INFO) // Yes INFO
845 && (levels[j].level == -2))) {
846 EXPECT_FALSE(__android_log_is_loggable(levels[i].level, tag,
847 ANDROID_LOG_DEBUG));
848 } else {
849 EXPECT_TRUE(__android_log_is_loggable(levels[i].level, tag,
850 ANDROID_LOG_DEBUG));
851 }
852 property_set(key, "");
853
854 fprintf(stderr, "i=%zu j=%zu property_set(\"%s\",\"%s\")\r",
855 i, j, key + base_offset, buf);
856 property_set(key + base_offset, buf);
857 if ((levels[i].level < levels[j].level)
858 || (levels[j].level == -1)
859 || ((levels[i].level < ANDROID_LOG_INFO) // Yes INFO
860 && (levels[j].level == -2))) {
861 EXPECT_FALSE(__android_log_is_loggable(levels[i].level, tag,
862 ANDROID_LOG_DEBUG));
863 } else {
864 EXPECT_TRUE(__android_log_is_loggable(levels[i].level, tag,
865 ANDROID_LOG_DEBUG));
866 }
867 property_set(key + base_offset, "");
868 }
869 }
870
871 // reset parms
872 snprintf(key, sizeof(key), "%s%s", log_namespace, tag);
873 property_set(key, hold[0]);
874 property_set(key + base_offset, hold[1]);
875 strcpy(key, log_namespace);
876 key[sizeof(log_namespace) - 2] = '\0';
877 property_set(key, hold[2]);
878 property_set(key + base_offset, hold[3]);
879 }
880
get4LE(const char * src)881 static inline int32_t get4LE(const char* src)
882 {
883 return src[0] | (src[1] << 8) | (src[2] << 16) | (src[3] << 24);
884 }
885
TEST(liblog,android_errorWriteWithInfoLog__android_logger_list_read__typical)886 TEST(liblog, android_errorWriteWithInfoLog__android_logger_list_read__typical) {
887 const int TAG = 123456781;
888 const char SUBTAG[] = "test-subtag";
889 const int UID = -1;
890 const int DATA_LEN = 200;
891 struct logger_list *logger_list;
892
893 pid_t pid = getpid();
894
895 ASSERT_TRUE(NULL != (logger_list = android_logger_list_open(
896 LOG_ID_EVENTS, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 1000, pid)));
897
898 ASSERT_LT(0, android_errorWriteWithInfoLog(
899 TAG, SUBTAG, UID, max_payload_buf, DATA_LEN));
900
901 sleep(2);
902
903 int count = 0;
904
905 for (;;) {
906 log_msg log_msg;
907 if (android_logger_list_read(logger_list, &log_msg) <= 0) {
908 break;
909 }
910
911 char *eventData = log_msg.msg();
912
913 // Tag
914 int tag = get4LE(eventData);
915 eventData += 4;
916
917 if (tag != TAG) {
918 continue;
919 }
920
921 // List type
922 ASSERT_EQ(EVENT_TYPE_LIST, eventData[0]);
923 eventData++;
924
925 // Number of elements in list
926 ASSERT_EQ(3, eventData[0]);
927 eventData++;
928
929 // Element #1: string type for subtag
930 ASSERT_EQ(EVENT_TYPE_STRING, eventData[0]);
931 eventData++;
932
933 ASSERT_EQ((int) strlen(SUBTAG), get4LE(eventData));
934 eventData +=4;
935
936 if (memcmp(SUBTAG, eventData, strlen(SUBTAG))) {
937 continue;
938 }
939 eventData += strlen(SUBTAG);
940
941 // Element #2: int type for uid
942 ASSERT_EQ(EVENT_TYPE_INT, eventData[0]);
943 eventData++;
944
945 ASSERT_EQ(UID, get4LE(eventData));
946 eventData += 4;
947
948 // Element #3: string type for data
949 ASSERT_EQ(EVENT_TYPE_STRING, eventData[0]);
950 eventData++;
951
952 ASSERT_EQ(DATA_LEN, get4LE(eventData));
953 eventData += 4;
954
955 if (memcmp(max_payload_buf, eventData, DATA_LEN)) {
956 continue;
957 }
958
959 ++count;
960 }
961
962 EXPECT_EQ(1, count);
963
964 android_logger_list_close(logger_list);
965 }
966
TEST(liblog,android_errorWriteWithInfoLog__android_logger_list_read__data_too_large)967 TEST(liblog, android_errorWriteWithInfoLog__android_logger_list_read__data_too_large) {
968 const int TAG = 123456782;
969 const char SUBTAG[] = "test-subtag";
970 const int UID = -1;
971 const int DATA_LEN = sizeof(max_payload_buf);
972 struct logger_list *logger_list;
973
974 pid_t pid = getpid();
975
976 ASSERT_TRUE(NULL != (logger_list = android_logger_list_open(
977 LOG_ID_EVENTS, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 1000, pid)));
978
979 ASSERT_LT(0, android_errorWriteWithInfoLog(
980 TAG, SUBTAG, UID, max_payload_buf, DATA_LEN));
981
982 sleep(2);
983
984 int count = 0;
985
986 for (;;) {
987 log_msg log_msg;
988 if (android_logger_list_read(logger_list, &log_msg) <= 0) {
989 break;
990 }
991
992 char *eventData = log_msg.msg();
993 char *original = eventData;
994
995 // Tag
996 int tag = get4LE(eventData);
997 eventData += 4;
998
999 if (tag != TAG) {
1000 continue;
1001 }
1002
1003 // List type
1004 ASSERT_EQ(EVENT_TYPE_LIST, eventData[0]);
1005 eventData++;
1006
1007 // Number of elements in list
1008 ASSERT_EQ(3, eventData[0]);
1009 eventData++;
1010
1011 // Element #1: string type for subtag
1012 ASSERT_EQ(EVENT_TYPE_STRING, eventData[0]);
1013 eventData++;
1014
1015 ASSERT_EQ((int) strlen(SUBTAG), get4LE(eventData));
1016 eventData +=4;
1017
1018 if (memcmp(SUBTAG, eventData, strlen(SUBTAG))) {
1019 continue;
1020 }
1021 eventData += strlen(SUBTAG);
1022
1023 // Element #2: int type for uid
1024 ASSERT_EQ(EVENT_TYPE_INT, eventData[0]);
1025 eventData++;
1026
1027 ASSERT_EQ(UID, get4LE(eventData));
1028 eventData += 4;
1029
1030 // Element #3: string type for data
1031 ASSERT_EQ(EVENT_TYPE_STRING, eventData[0]);
1032 eventData++;
1033
1034 size_t dataLen = get4LE(eventData);
1035 eventData += 4;
1036
1037 if (memcmp(max_payload_buf, eventData, dataLen)) {
1038 continue;
1039 }
1040 eventData += dataLen;
1041
1042 // 4 bytes for the tag, and 512 bytes for the log since the max_payload_buf should be
1043 // truncated.
1044 ASSERT_EQ(4 + 512, eventData - original);
1045
1046 ++count;
1047 }
1048
1049 EXPECT_EQ(1, count);
1050
1051 android_logger_list_close(logger_list);
1052 }
1053
TEST(liblog,android_errorWriteWithInfoLog__android_logger_list_read__null_data)1054 TEST(liblog, android_errorWriteWithInfoLog__android_logger_list_read__null_data) {
1055 const int TAG = 123456783;
1056 const char SUBTAG[] = "test-subtag";
1057 const int UID = -1;
1058 const int DATA_LEN = 200;
1059 struct logger_list *logger_list;
1060
1061 pid_t pid = getpid();
1062
1063 ASSERT_TRUE(NULL != (logger_list = android_logger_list_open(
1064 LOG_ID_EVENTS, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 1000, pid)));
1065
1066 ASSERT_GT(0, android_errorWriteWithInfoLog(
1067 TAG, SUBTAG, UID, NULL, DATA_LEN));
1068
1069 sleep(2);
1070
1071 int count = 0;
1072
1073 for (;;) {
1074 log_msg log_msg;
1075 if (android_logger_list_read(logger_list, &log_msg) <= 0) {
1076 break;
1077 }
1078
1079 char *eventData = log_msg.msg();
1080
1081 // Tag
1082 int tag = get4LE(eventData);
1083 eventData += 4;
1084
1085 if (tag == TAG) {
1086 // This tag should not have been written because the data was null
1087 count++;
1088 break;
1089 }
1090 }
1091
1092 EXPECT_EQ(0, count);
1093
1094 android_logger_list_close(logger_list);
1095 }
1096
TEST(liblog,android_errorWriteWithInfoLog__android_logger_list_read__subtag_too_long)1097 TEST(liblog, android_errorWriteWithInfoLog__android_logger_list_read__subtag_too_long) {
1098 const int TAG = 123456784;
1099 const char SUBTAG[] = "abcdefghijklmnopqrstuvwxyz now i know my abc";
1100 const int UID = -1;
1101 const int DATA_LEN = 200;
1102 struct logger_list *logger_list;
1103
1104 pid_t pid = getpid();
1105
1106 ASSERT_TRUE(NULL != (logger_list = android_logger_list_open(
1107 LOG_ID_EVENTS, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 1000, pid)));
1108
1109 ASSERT_LT(0, android_errorWriteWithInfoLog(
1110 TAG, SUBTAG, UID, max_payload_buf, DATA_LEN));
1111
1112 sleep(2);
1113
1114 int count = 0;
1115
1116 for (;;) {
1117 log_msg log_msg;
1118 if (android_logger_list_read(logger_list, &log_msg) <= 0) {
1119 break;
1120 }
1121
1122 char *eventData = log_msg.msg();
1123
1124 // Tag
1125 int tag = get4LE(eventData);
1126 eventData += 4;
1127
1128 if (tag != TAG) {
1129 continue;
1130 }
1131
1132 // List type
1133 ASSERT_EQ(EVENT_TYPE_LIST, eventData[0]);
1134 eventData++;
1135
1136 // Number of elements in list
1137 ASSERT_EQ(3, eventData[0]);
1138 eventData++;
1139
1140 // Element #1: string type for subtag
1141 ASSERT_EQ(EVENT_TYPE_STRING, eventData[0]);
1142 eventData++;
1143
1144 // The subtag is longer than 32 and should be truncated to that.
1145 ASSERT_EQ(32, get4LE(eventData));
1146 eventData +=4;
1147
1148 if (memcmp(SUBTAG, eventData, 32)) {
1149 continue;
1150 }
1151 eventData += 32;
1152
1153 // Element #2: int type for uid
1154 ASSERT_EQ(EVENT_TYPE_INT, eventData[0]);
1155 eventData++;
1156
1157 ASSERT_EQ(UID, get4LE(eventData));
1158 eventData += 4;
1159
1160 // Element #3: string type for data
1161 ASSERT_EQ(EVENT_TYPE_STRING, eventData[0]);
1162 eventData++;
1163
1164 ASSERT_EQ(DATA_LEN, get4LE(eventData));
1165 eventData += 4;
1166
1167 if (memcmp(max_payload_buf, eventData, DATA_LEN)) {
1168 continue;
1169 }
1170
1171 ++count;
1172 }
1173
1174 EXPECT_EQ(1, count);
1175
1176 android_logger_list_close(logger_list);
1177 }
1178
TEST(liblog,android_errorWriteLog__android_logger_list_read__success)1179 TEST(liblog, android_errorWriteLog__android_logger_list_read__success) {
1180 const int TAG = 123456785;
1181 const char SUBTAG[] = "test-subtag";
1182 struct logger_list *logger_list;
1183
1184 pid_t pid = getpid();
1185
1186 ASSERT_TRUE(NULL != (logger_list = android_logger_list_open(
1187 LOG_ID_EVENTS, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 1000, pid)));
1188
1189 ASSERT_LT(0, android_errorWriteLog(TAG, SUBTAG));
1190
1191 sleep(2);
1192
1193 int count = 0;
1194
1195 for (;;) {
1196 log_msg log_msg;
1197 if (android_logger_list_read(logger_list, &log_msg) <= 0) {
1198 break;
1199 }
1200
1201 char *eventData = log_msg.msg();
1202
1203 // Tag
1204 int tag = get4LE(eventData);
1205 eventData += 4;
1206
1207 if (tag != TAG) {
1208 continue;
1209 }
1210
1211 // List type
1212 ASSERT_EQ(EVENT_TYPE_LIST, eventData[0]);
1213 eventData++;
1214
1215 // Number of elements in list
1216 ASSERT_EQ(3, eventData[0]);
1217 eventData++;
1218
1219 // Element #1: string type for subtag
1220 ASSERT_EQ(EVENT_TYPE_STRING, eventData[0]);
1221 eventData++;
1222
1223 ASSERT_EQ((int) strlen(SUBTAG), get4LE(eventData));
1224 eventData +=4;
1225
1226 if (memcmp(SUBTAG, eventData, strlen(SUBTAG))) {
1227 continue;
1228 }
1229 ++count;
1230 }
1231
1232 EXPECT_EQ(1, count);
1233
1234 android_logger_list_close(logger_list);
1235 }
1236
TEST(liblog,android_errorWriteLog__android_logger_list_read__null_subtag)1237 TEST(liblog, android_errorWriteLog__android_logger_list_read__null_subtag) {
1238 const int TAG = 123456786;
1239 struct logger_list *logger_list;
1240
1241 pid_t pid = getpid();
1242
1243 ASSERT_TRUE(NULL != (logger_list = android_logger_list_open(
1244 LOG_ID_EVENTS, ANDROID_LOG_RDONLY | ANDROID_LOG_NONBLOCK, 1000, pid)));
1245
1246 ASSERT_GT(0, android_errorWriteLog(TAG, NULL));
1247
1248 sleep(2);
1249
1250 int count = 0;
1251
1252 for (;;) {
1253 log_msg log_msg;
1254 if (android_logger_list_read(logger_list, &log_msg) <= 0) {
1255 break;
1256 }
1257
1258 char *eventData = log_msg.msg();
1259
1260 // Tag
1261 int tag = get4LE(eventData);
1262 eventData += 4;
1263
1264 if (tag == TAG) {
1265 // This tag should not have been written because the data was null
1266 count++;
1267 break;
1268 }
1269 }
1270
1271 EXPECT_EQ(0, count);
1272
1273 android_logger_list_close(logger_list);
1274 }
1275