Commit Graph

349 Commits

Author SHA1 Message Date
Mark Salyzyn 142b43d4ab liblog: BM_log_latency improvement
This reduces BM_log_latency from ~300ns to ~100ns.  Because, well, we
read the clock earlier and that is what BM_log_latency tries to
measure.  The one major improvement in the switch from kernel logger
to user space logger was that we picked up the timestamp in the
context of the caller before doing anything else, but alas changes
over time neglected this fact and placed isloggable checking ahead
of this important fact.

Test: liblog_benchmarks, check results
Change-Id: I4bc9fc3cf8b1659e88417d967b1d0f3743f9e456
2017-01-20 17:53:27 +00:00
Jorge Lucangeli Obes f4ae42f6a8 Check the return value of setuid(2).
I'd like to mark setuid() WARN_UNUSED_RESULT to prevent security bugs.
This line would break because the file is compiled with -Werror.

Bug: 34251640
Test: Build, run unit test.
Change-Id: Ibb6fa5e5b899d47f77f2a32da762165de310101d
2017-01-13 15:43:45 +00:00
Mark Salyzyn 65e1e6284c liblog: retry -ENOTCONN | -ECONNREFUSED | -ENOENT indefinitely
Deal with recovering after transitory failures surrounding logd
crash or recovery.  Improve the chances that the logging functions
can work in a signal handler, not officially supported, but making
sure logging is not blamed for system lockups when misused.

Reorder gTests so that setuid(AID_SYSTEM) is performed after
liblog.enoent test, and that this occurs after other tests that
like to see buffers with content in them as we stop logd.

Test: gTest liblog-unit-tests --gtest_filter=liblog.enoent
Bug: 33755074
Change-Id: I66f88599534614b7b61da6b2ae5fe099ebaced3a
2017-01-09 15:51:09 +00:00
Mark Salyzyn b52f445dbb liblog: test: switch to private event structures
Some tests use hard-coded offsets to interpret the binary
events buffers.  Switch to using the private event structures
to access the components of common event messages.

Test: gTest liblog-unit-tests
Bug: 33755074
Change-Id: I17447814583099d5ec417a54389e962158456005
2017-01-06 22:13:34 +00:00
Dan Albert 9a41bcecc6 Unversion NDK stub libraries.
The system versions of these libraries aren't versioned yet.

Bug: https://github.com/android-ndk/ndk/issues/278
Test: make ndk
Change-Id: Icf5ff9921441d3e252771aef37002c772c08cbd0
2017-01-06 11:04:15 -08:00
Elliott Hughes 9b3b119912 Don't use bare `noreturn` in log.h.
toybox has a #define noreturn that trips over this.

Also move `format` out of the way, just in case.

Bug: https://github.com/android-ndk/ndk/issues/271
Test: builds
Change-Id: Ib8811136b4b422ff74625509539a5464a3c9af18
2017-01-03 13:17:42 -08:00
Mark Salyzyn af3503cff4 liblog: test failures due to permission issues
Test: gTest liblog-unit-tests passes
Change-Id: Ia9452b3ee9e6068723e8bef48c4d88d3769951a8
2016-12-27 10:01:42 -08:00
Mark Salyzyn fc148f7f33 liblog: add IF_ALOG_RATELIMIT
IF_ALOG_RATELIMIT()
    ALOGE("Only one message globally using IF_ALOG_RATELIMIT()"
          " in the process may appear ever ten seconds,"
          " (%s)", strerror(errno));

static time_t last; /* initial state zero */
IF_ALOG_RATELIMIT_LOCAL(60, &last)
    ALOGE("Only one message locally may appear every minute,"
          " (%s)", strerror(errno));

These new calls are guaranteed not to affect the value of a
non-zero errno to simplify logging of errors.  However, the
ALOGE calls in the above examples may update the errno value
upon their return.

Test: gTest liblog-unit-tests --gtest_filter=liblog.__android_log_ratelimit
Bug: 33535908
Change-Id: Id8cc192fc7d14504ffd418933cf88ae945c089f2
2016-12-21 21:36:14 +00:00
Mark Salyzyn 5bd8f2d956 liblog: pmsg read permissions for AID_LOGD
Test: gTest liblog-unit-test and logd-unit-tests
Bug: 31456426
Change-Id: I7a2fe8245ecd651883f7851ce71b6c45e373af82
2016-12-19 15:57:01 +00:00
Mark Salyzyn 774e04f779 liblog: move log_is_loggable.c to properties.c
Just makes sense cleanup

Test: gTest liblog-unit-tests
Bug: 33535908
Change-Id: I85de049f3cd73a473d56db5970d42eee5f9f70a8
2016-12-16 08:43:56 -08:00
Treehugger Robot 8b99ef6c21 Merge "liblog: event_tag_map use unordered_map" 2016-12-16 01:57:03 +00:00
Mark Salyzyn 700fb87648 liblog: event_tag_map use unordered_map
>3 times faster access for lookup functions.  Code simplification and
C++ coding style conversion.  android_lookupEventTagNum has been
expanded to utilize the Format match, and then drops down to just
Tag match.

Performance testing on Hikey, all services stopped, shell only access,
CPU not locked had good repeatability.

$ adb reboot ; adb wait-for-device ; adb shell su root stop

Before this adjustment using binary search:

$ /data/nativetest64/liblog-benchmarks/liblog-benchmarks BM_lookupEvent*
                          iterations      ns/op
Precharge: start
Precharge: stop 231
BM_lookupEventTag           10000000        153
BM_lookupEventTag_NOT       20000000        139
BM_lookupEventFormat        10000000        153

After this adjustment strictly using std::unordered_map lookup:

$ /data/nativetest64/liblog-benchmarks/liblog-benchmarks BM_lookupEvent*
                          iterations      ns/op
Precharge: start
Precharge: stop 231
BM_lookupEventTag           50000000         56
BM_lookupEventTag_NOT      100000000         21
BM_lookupEventFormat        50000000         56

Test: gTest logd-unit-tests and liblog-unit-tests, liblog-benchmarks.
Bug: 31456426
Change-Id: I1cfc3d641c3ea9ab08d455efe0c844d3a6381440
2016-12-15 22:32:37 +00:00
Mark Salyzyn a91b426268 liblog: clean up SafetyNet unit tests
Move active code into helpers.

Test: gTest liblog-unit-tests
Change-Id: I5ade96edd71b7d773386f4d99eddbad076d10405
2016-12-13 13:47:48 -08:00
Mark Salyzyn ed9dc8abe2 liblog: switch event_tag_map.c to event_tag_map.cpp
NB: recent activities on event_tag_map.c were to allow
    this transition to be unremarkable.

Test: compile
Bug: 31456426
Change-Id: I13e1771a001874244711a5ac3023861c2a5f8c7d
2016-12-01 15:42:03 -08:00
Mark Salyzyn 3cd9e31446 liblog: fortify event_log_tags test
Robustness fortification.  Deal with gtest failure if event-log-tags
file is updated, adb sync for example, and thus will report
Shared_Dirty instead of Shared_Clear.  Add check for Private_Dirty
and Private_Clean being clear at zero too as a bonus.

Test: gTest liblog-unit-tests --gtest_filter=liblog.event_log_tags
Bug: 31456426
Change-Id: Id912929fdd65499aa532a15653ef387a997a5054
2016-11-30 11:08:46 -08:00
Treehugger Robot f1f7333e7c Merge "liblog: CTS test" 2016-11-30 16:25:11 +00:00
Treehugger Robot 4afb3ef952 Merge "liblog: event_tag_map benchmark" 2016-11-30 15:31:11 +00:00
Treehugger Robot 1abc3cd641 Merge changes Ia0ca36fc,Ib42c0635
* changes:
  Enable liblog on host bionic
  Enable libbase/libutils/libziparchive on host bionic
2016-11-30 05:59:53 +00:00
Dan Willemsen 0910d2dbb9 Enable liblog on host bionic
Some of the __BIONIC__ checks were actually looking for an android
device. Host bionic has __BIONIC__, but not __ANDROID__.

Bug: 31559095
Test: Test linux_bionic compile
Change-Id: Ia0ca36fc9486fe8ea7e5d1b2e26ab0491903723c
2016-11-29 13:39:55 -08:00
Treehugger Robot 9bfd9f558b Merge "system/core: replace EVENT_TAG_MAP_FILE with NULL" 2016-11-29 19:37:48 +00:00
Mark Salyzyn 52ed8c68ee liblog: CTS test
Utilize liblog-unit-tests as a CTS test

Replacement for EventLogTest#testWriteEventWithOversizeValue
along with some other mandatory logging functionality.

Test: run cts tests
Bug: 26235244
Change-Id: I71f549bd0b93f6c41e1f91565b0fbddf042e4991
2016-11-29 08:40:16 -08:00
Mark Salyzyn 0b37d01f72 liblog: event_tag_map benchmark
Tested on Hikey, all services stopped, shell only access, CPUs not
locked.

$ /data/nativetest64/liblog-benchmarks/liblog-benchmarks BM_lookupEvent*
                          iterations      ns/op
Precharge: start
Precharge: stop 231
BM_lookupEventTag           10000000        153
BM_lookupEventTag_NOT       20000000        139
BM_lookupEventFormat        10000000        153

Test: run benchmarks
Bug: 31456426
Change-Id: Ice3ffa0b061d9a6b917718b2d9aedcc2348b7005
2016-11-28 15:15:58 -08:00
Mark Salyzyn 1179eb8048 system/core: replace EVENT_TAG_MAP_FILE with NULL
NULL represents system default.  In the future, NULL could represent
static and dynamic tags, which can come from multiple files based on
implementation details in the liblog library.

Test: gTest logd-unit-tests & liblog-unit-tests
Bug: 31456426
Change-Id: I0e3d296de81ca299ae63d7b83781639ee67ec298
2016-11-21 11:13:02 -08:00
Mark Salyzyn 2ca4f49476 liblog: add private android_log_write_list_buffer()
Allows us to compose an event message for our own in-memory purposes.
Will be used to compose an event message in logd and directly write
it to just the pmsg buffer.  Provide an internal enhanced C++ wrapper
for event handling.

Test: gTest liblog-unit-tests --gtest_filter=liblog.android_log_write_list_buffer
Bug: 31456426
Change-Id: I98246898ba580f9e506baba8af2fd1b26a2a8aae
2016-11-21 09:46:39 -08:00
Mark Salyzyn 472245d962 liblog: move android_log_event_context class to log/log_event_list.h
rename class from android_log_event_context to android_log_event_list

Test: gTest logcat-unit-tests
Bug: 31992412
Bug: 31456426
Change-Id: Ib61cbca7d453837d64959c56b0e11f8c5edbfbdd
2016-11-21 09:46:34 -08:00
Mark Salyzyn 538bc12c08 logcat: add hidden --debug flag and cleanup
Allow us to debug corrupted log messages. Fix liblog to propagate
errors correctly and repair a gtest that failed.

Test: liblog-unit-tests --gtest_filter=liblog.__android_log_bswrite_and_print___max
      logcat -b events --debug -t 50
Bug: 32903864
Change-Id: Ib4eb9f466777cd23b8b54728d36354590d07869a
2016-11-16 15:46:42 -08:00
Mark Salyzyn 1a57ae3a7d liblog: logprint: report truncated event log contents if error
We need to accept that a log tag can contain no payload.  For those
that are corrupted, and to aid debugging, report what we did manage
to interpret.  Report last character as a ! for corruption, and ^
for truncation.  Fix a few Android Coding standard issues.

Test: gTest logcat-unit-tests
Bug: 32903864
Change-Id: Id11bef3a7b6569305c51701dd66c45d2038d6628
2016-11-15 14:46:34 -08:00
Mark Salyzyn 53e9fc7915 liblog: android_closeEventTagMap pointer check
Followup to c/278768 where failure to open tag map can
result in segment violation in android_closeEventTagMap.
Add check for pointer value = -1 to bypass call to close.

Test: gTest liblog-unit-tests, logcat-unit-tests & logd-unit-tests
Bug: 30963384
Bug: 31456426
Change-Id: I20547e55d7e29682fde4538bc1fc6d83b4535d49
2016-11-09 10:16:38 -08:00
Mark Salyzyn 4fd0507b20 liblog: logcat: logprint support -v descriptive
Expand logprint feature to pull out the log tag description
fields, parse them and merge into the logging content.  Add
-v descriptive, -v colour(british, hidden) and -v help. Also
added a unit test for the descriptive format borrowing from
event tags that have been unchanged since 2009.

Had to add -v help because we have too many undocumented
formats and format adverbs.

Test: gTest logcat-unit-tests --gtest_filter=logcat.descriptive
Bug: 31456426
Change-Id: I93a1c003b7a3f4c332544946fdedb7277919cec3
2016-11-04 15:22:52 -07:00
Mark Salyzyn 530711b39e liblog: add android_lookupEventFormat_len
Test: compile
Bug: 31456426
Change-Id: I283fec89431c18af788fa0477a2ab78792221878
2016-11-04 15:22:52 -07:00
Mark Salyzyn 5febc51318 liblog: test report pmsg not configured if ENOMEM return
NB: bionic stdio is broken when providing appropriate errno value(s)
    on failure so libc.__pstore_append will not report pmsg
    misconfigured correctly on android for now.

Test: misconfigured kernel, watch for this message in liblog-unit-tests
Change-Id: Ifb1b550c7d3a3888000459c2f68c392cc23c379f
2016-11-03 11:20:59 -07:00
Mark Salyzyn a28525293d liblog: remove reference to log/logger.h
Test: compile
Bug: 31992412
Change-Id: Idd52072d0f8c657ac53dc3e6b505a66c47a94357
2016-10-26 14:59:42 -07:00
Mark Salyzyn aeaaf81c2c liblog: logd: logcat: Split out log/logger.h into public and private.
log/logger.h pieces moved into log/log.h.  Correct for some
minor Android Coding standards.

Test: gTests liblog-unit-tests, logd-unit-tests and logcat-unit-tests
Bug: 19235719
Bug: 26552300
Bug: 31289077
Bug: 31456426
Change-Id: I0a19fd8788eec20a582e72e4c62c04534bdb1b9a
2016-10-24 11:12:49 -07:00
Mark Salyzyn 749a298dfd liblog: restructure log/log.h and android/log.h
We went too far, so this is a partial revert, part deux.

Keep general purpose logging macros in android/log.h for the NDK.
More internal features like Radio, System and Events logging are
moved back to log/log.h.  Correct liblog ndk symbols.  Correct for
some Android Coding standards.

Test: compile
Bug: 31992412
Change-Id: Id3731496fa226e8c170305d0d2a1859e8cf67e14
2016-10-24 11:03:49 -07:00
Treehugger Robot c741dd4838 Merge "Add license to ndk_headers." 2016-10-20 22:12:40 +00:00
Dan Albert 286b2eaa52 Add license to ndk_headers.
Test: make ndk
Bug: None
Change-Id: Iaba7368b89ec446b5c65c7c127a98914bd949496
2016-10-20 10:18:27 -07:00
Mark Salyzyn cfd5b080af system/core: preparation to pull back interfaces from android/log.h
Point to log/log.h where necessary, define LOG_TAG where necessary.
Accept that private/android_logger.h is suitable replacement for
log/logger.h and android/log.h.

Correct liblog/README

Effectively a cleanup and controlled select revert of
'system/core: drop or replace log/logger.h' and
'system/core: Replace log/log.h with android/log.h'.

Test: compile
Bug: 30465923
Change-Id: Ic2ad157bad6f5efe2c6af293a73bb753300b17a2
2016-10-20 08:11:39 -07:00
Mark Salyzyn e455373b57 liblog: Add private interfaces for buffer size properties
Add private function __android_logger_get_buffer_size() to read
properties and compose the default buffer size.  This interface
complements the existing android_looger_get_size() which returns
the logd setting which can differ at runtime.  For use in logd
and dumpstate.  Side effect is we also add the private functions
__android_logger_property_get_bool() and
__android_logger_valid_buffer_size() for reuse in logd.

Test: gTest liblog-unit-test, logd-unit-tests and logcat-unit-tests in
      combination with commit 'logd: Use private interfaces for
      buffer size properties'
Bug: 31750617
Change-Id: Id95cb68f775ef6b427c122e10f6f8291d336d184
2016-10-18 09:48:55 -07:00
Treehugger Robot 915d620359 Merge "liblog: LIBLOG_ABI_PRIVATE __android_log_is_debuggable()" 2016-10-17 21:46:37 +00:00
Treehugger Robot 6da1ea0e48 Merge "liblog: __android_log_pmsg_file_write() cleanup" 2016-10-17 14:16:46 +00:00
Dan Albert b7c3996f7c Continue using the legacy NDK android/log.h.
system/core/android/log.h needs some work before it can be included in
the NDK. It defines a *lot* of macros that previously were usable
names in NDK sources that used android/log.h. As an example, the
following file defines LOG_TAG as a variable, but the variable name
gets macro replaced if we use the current android/log.h.
4adc1515f8/framework/platform/android/tcuTestLogParserJNI.cpp (41)

For now, we keep a copy of the old NDK android/log.h in
legacy-ndk-includes.

Test: make checkbuild
Bug: http://b/30465923
Change-Id: I8ce942d1ee2f8f0d4c27130802c03992a1b85ec4
2016-10-14 13:12:29 -07:00
Mark Salyzyn 9ea359fce0 liblog: LIBLOG_ABI_PRIVATE __android_log_is_debuggable()
Allow our own libraries to use this privately instead of
running the less efficient get_properties and doing the math.

Test: compile and boot smoke test
Bug: 27566046
Bug: 31456426
Change-Id: I2f677276d27fbcb6af01b600ac1d9891c8938d43
2016-10-14 08:00:41 -07:00
Treehugger Robot 955648a915 Merge "Rely on the platform -std default." 2016-10-14 02:28:38 +00:00
Mark Salyzyn db8a266aea liblog: __android_log_pmsg_file_write() cleanup
__android_log_pmsg_file_write() will open /dev/pmsg0 if not
already, and will close it if we opened it.

Added atomic access to the android_log_context as insurance.

Fortify and correct pmsg tests.

Test: gTest liblog-unit-tests --gtest_filter=liblog.__android_log_pmsg_file_*
Bug: 31958686
Change-Id: I2cf6f971b6968938f471fda67367efe20dae3004
2016-10-13 21:43:42 +00:00
Elliott Hughes 36e0d390a2 Rely on the platform -std default.
Bug: http://b/32019064
Test: builds
Change-Id: I18a1d816d63b64601485045070851f32d44e85eb
2016-10-10 14:31:12 -07:00
Mark Salyzyn 6debf985aa liblog: adb: move security interfaces to private
Test: Compile & adb functioning
Bug: 19235719
Bug: 26552300
Bug: 31289077
Bug: 31456426
Change-Id: I7ad8963bcca3d8b5c37b547c11d163b652d35556
2016-10-10 15:15:45 +00:00
Mark Salyzyn 37c9451349 system/core: drop or replace log/logger.h
debuggerd does not require log/logger.h, can use android/log.h
In some cases, mark why log/logger.h was required.

Test: Compile and boot smoke test
Bug: 26552300
Bug: 31289077
Bug: 31456426
Change-Id: Ia34987e25a01d81971ec8d785415f732b8376c4f
2016-10-04 09:09:10 -07:00
Mark Salyzyn 807e40ecc9 liblog: logd: Add android_lookupEventTag_len()
Allows us to mitigate the impact of MAP_PRIVATE and copy on write by
calling android_lookupEventTag_len instead of android_lookupEventTag,
and delaying the copy on write impact to the later.  We return a
string length in a supplied location along with the string pointer
with android_lookupEventTag_len(const EventTagMap* map, size_t* len,
int tag).  The string is not guaranteed to be nul terminated.  Since
android_lookupEventTag() called even once can cause the memory
impact, we will mark it as deprecated, but we currently have no
timeframe for removal since this is a very old interface.

Add an API for __android_log_is_loggable_len() that accepts the non
null terminated content and fixup callers that would gain because the
length is known prior to the call either in the compiler or at
runtime.  Tackle transition to android_lookupEventTag_len() and
fixup callers.

On any application that performs logging (eg: com.android.phone)

/proc/<pid>/smaps before:

xxxxxxxxxx-xxxxxxxxxx rw-p 00000000 fd:00 463 /system/etc/event-log-tags
Size:                 20 kB
Rss:                  20 kB
Pss:                   1 kB
Shared_Clean:          0 kB
Shared_Dirty:         20 kB
Private_Clean:         0 kB
Private_Dirty:         0 kB
Referenced:            0 kB
Anonymous:            20 kB
AnonHugePages:         0 kB
Swap:                  0 kB
SwapPss:               0 kB
KernelPageSize:        4 kB
MMUPageSize:           4 kB
Locked:                0 kB
VmFlags: rd wr mr mw me ac

/proc/<pid>/smaps after:

xxxxxxxxxx-xxxxxxxxxx rw-p 00000000 fd:00 1773 /system/etc/event-log-tags
Size:                 20 kB
Rss:                  20 kB
Pss:                   1 kB
Shared_Clean:         20 kB  (was 0kB)
Shared_Dirty:          0 kB  (was 20kB)
Private_Clean:         0 kB
Private_Dirty:         0 kB
Referenced:           20 kB  (was 0kB)
Anonymous:             0 kB  (was 20kB)
AnonHugePages:         0 kB
Swap:                  0 kB
SwapPss:               0 kB
KernelPageSize:        4 kB
MMUPageSize:           4 kB
Locked:                0 kB
VmFlags: rd wr mr mw me ac

Added liblog-unit-tests --gtest_filter=liblog.event_log_tags to
check for Shared_Clean: to not be 0 and Anonymous: to be 0 for
all processes referencing event-log-tags.  Which can include multiple
references to /system/etc/event-log-tags and future possible refs to
/data/misc/logd/event-log-tags and /dev/event-log-tags.  We want
failure messages to help point to errant code using the deprecated
interface.

This change saves 1/4MB of memory or more on a typical system.

Test: gTest liblog-unit-tests
Bug: 31456426
Change-Id: I9e08e44d9092bd96fe704b5709242e7195281d33
2016-10-03 11:08:34 -07:00
Mark Salyzyn 9633b919d7 liblog: Move liblog tag from 1005 to 1006
Allow logd to add another "consecutive" log tag

Test: gTest liblog-unit-tests, check for liblog in logcat afterwards
Bug: 31456426
Change-Id: I0c25e038878ec9a0cf368a33a63f8345c68749c3
2016-09-30 12:47:05 -07:00
Mark Salyzyn 6584d0a35a liblog: Replace log/log.h with android/log.h
Move all liblog related content into android/log.h, and make
log/log.h points to android/log.h.

Test: Compile
Bug: 26552300
Bug: 31289077
Change-Id: I858e0ebe047b86f2a8530a99bc9c380d3d58edbb
2016-09-30 12:47:05 -07:00