Commit Graph

377 Commits

Author SHA1 Message Date
Mark Salyzyn 8f2492f582 liblog: benchmark: Use local LOGGER_NULL frontend
Additional benchmarks to check the effects and performance of the
frontend changes.

Test: manual liblog-benchmarks
Bug: 27405083
Change-Id: I2a9dba81b70e9d71cdb8de1b35e8dff099ad6038
2017-02-08 13:37:44 -08:00
Mark Salyzyn 850d06e1c9 liblog: Add android_set_log_frontend
android_set_log_frontend allows one to select LOGGER_DEFAULT,
LOGGER_LOGD or LOGGER_NULL, the latter allows a runtime mechanism to
turn logging on or off.  LOGGER_DEFAULT is LOGGER_LOGD.

Test: gTest liblog-unit-tests notably liblog.android_set_log_frontend
      and liblog-benchmarks before and after.
Bug: 27405083
Change-Id: I365dbee9f7d83112da0ef8d1cace748d247773c8
2017-02-08 13:37:41 -08:00
Treehugger Robot a3b6d30ba7 Merge "liblog: fix an undefined-behavor in __write_to_log_daemon()" 2017-02-08 17:21:58 +00:00
Ting-Yuan Huang 6efb877973 liblog: fix an undefined-behavor in __write_to_log_daemon()
The behavior of passing NULL to c-string functions is undefined.

Test: passed clang-tidy checks
Bug: none

Change-Id: Ie7bcc43cd19bc4a1c314381af3929eae0a6154b9
2017-02-07 16:42:53 -08:00
Ting-Yuan Huang 106c3e6189 liblog: fix a memory leak in __android_log_pmsg_file_write()
Free the strdup()-ed filename before returning error.

Test: passed clang-tidy checks
Bug: none
Change-Id: I555492cb4e50400db758f7c721647a8747874a01
2017-02-07 15:53:32 -08:00
Mark Salyzyn 7048f0b1cb liblog: logger.h fortify comments
Test: none
Bug: 27405083
Change-Id: I88ae9f33daa457454edfc5e95cb9e9e74e8cd5f0
2017-02-07 14:16:09 -08:00
Elliott Hughes 5bae1b866d Make __android_log_assert behave more like libc asserts.
If we don't output to stderr too, not only is it annoying to shell users (who
won't see anything), it prevents us from writing better gtests that actually
make assertions about the assert message.

Bug: http://b/23675822
Test: libutils tests still pass
Change-Id: I62b3144c385cba4dde485f0b0f9b42aeaef51e9a
2017-02-06 10:54:00 -08:00
Mark Salyzyn c9e5f37166 liblog: add android_lookupEventTagNum
android_lookupEventTagNum added.  Adds support for creating a new
log tag at runtime, registered to the logd service.

Tested on Hikey, all services stopped, shell only access, CPUs not
locked (there is enough repeatability on this platform).

$ /data/nativetest64/liblog-benchmarks/liblog-benchmarks BM_lookupEventTagNum

                          iterations      ns/op
Precharge: start
Precharge: stop 231
NB: only Tag matching, linear lookup (as reference, before unordered_map)
BM_lookupEventTagNum         1000000       1017
NB: unordered_map with full Tag & Format lookup, but with Tag hashing
BM_lookupEventTagNum         2000000        683
NB: with full Tag & Format hash and lookup for matching
BM_lookupEventTagNum         2000000        814
NB: only Tag matching (Hail Mary path)
BM_lookupEventTagNum         5000000        471

Because the database can now be dynamic, we added reader/writer locks
which adds a 65ns (uncontended) premium on lookups, and switch to
check for an allocation adds 25ns (either open code, or using
string_view, no difference) which means our overall speed takes 90%
as long as the requests did before we switched to unordered_map.
Faster than before where we originally utilized binary lookup on
static content, but not by much.  Dynamic updates that are not cached
locally take the following times to acquire long path to logd to
generate.

BM_lookupEventTag           20000000         139
BM_lookupEventTag_NOT       20000000         87
BM_lookupEventFormat        20000000         139
BM_lookupEventTagNum_logd_new   5000         335936
BM_lookupEventTagNum_logd_existing 10000     249226

The long path pickups are mitigated by the built-in caching, and
the public mapping in /dev/event-log-tags.

SideEffects: Event tags and signal handlers do not mix
Test: liblog benchmarks
Bug: 31456426
Change-Id: I69e6489d899cf35cdccffcee0d8d7cad469ada0a
2017-02-02 15:21:15 -08:00
Mark Salyzyn 7da7fab790 liblog: add /dev/event-log-tags for Tag Map
android_openEventTagMap(NULL) will open and mix content from
/system/etc/event-log-tags and /dev/event-log-tags.  Only
reports identicals if global.

Test: gTest logd-unit-tests and liblog-unit-tests, liblog-benchmarks.
Bug: 31456426
Change-Id: Ic17d52a7829a4daaf013828d08fc1c09446ae8ef
2017-02-02 14:24:26 -08:00
Treehugger Robot 26a714a0ab Merge "logcat: test: inject() tuning" 2017-01-31 15:59:22 +00:00
Mark Salyzyn 9b4d7e1c38 logcat: test: inject() tuning
Add a hidden -v nsec flag to logcat (actually logprint in liblog.so)
so that we can do more exacting tests of logcat.tail_time.  Halve the
spam pressure of logcat.tail_* in inject() routine, and give us a few
more retries at the higher counts.  Add instrumentation to
logcat.logrotate failures.  Add inject for logcat.year test.

Test: gTest logcat-unit-tests
Bug: 34454772
Change-Id: If6f3bd21892c8a2b9ccee8c8bbf592a1ae0b2a57
2017-01-30 15:42:56 -08:00
Mark Salyzyn bdac221cc3 Revert "Continue using the legacy NDK android/log.h."
Use refreshed android/log.h for NDK

This effectively a modern revert of the commit
b7c3996f7c

Test: build
Bug: 30465923
Bug: 34250038
Change-Id: I7d4a5134bb711051283c36a2d5bc803436dca12e
2017-01-30 22:14:59 +00:00
Treehugger Robot ff21dba167 Merge "liblog: export log/log_read.h to vndk" 2017-01-27 02:14:34 +00:00
Treehugger Robot 296f7dad19 Merge "Don't use private libc++ macros." 2017-01-27 00:42:21 +00:00
Mark Salyzyn 9b844bc6e1 liblog: export log/log_read.h to vndk
Test: gTest liblog-unit-tests
Bug: 34250038
Change-Id: I2904b950eb399a4f34c5da31b51703e8f2d5ea93
2017-01-26 16:10:59 -08:00
Dan Albert 9ccdd5fb17 Don't use private libc++ macros.
The visibility macros just expand to the defaults, so this isn't
needed anyway.

Test: mm
Bug: http://b/34740564
Change-Id: If0ba6b412554300823219405c1e801ceec747dd0
2017-01-26 14:58:26 -08:00
Mark Salyzyn 21de8aca67 liblog: add log/log_read.h
Move log reading definitions to their own home.

struct logger_entry
struct logger_entry_v2
struct logger_entry_v3
struct logger_entry_v4
LOGGER_ENTRY_MAX_PAYLOAD
LOGGER_ENTRY_MAX_LEN
struct log_msg
android_logger_get_id()
android_logger_clear()
android_logger_get_log_size()
android_logger_get_log_readable_size()
struct logger_list
android_logger_get_statistics()
android_logger_get_prune_list()
android_logger_set_prune_list()
android_logger_list_alloc()
android_logger_list_alloc_time()
android_logger_list_free()
android_logger_list_read()
android_logger_open()
android_logger_list_open()

Deal with a possible scenario where fcntl.h was not included at the
top of the source files, and log/log_read.h inclusion of fcntl.h
conflicts with a source file inclusion of sys/cdefs.h definition of
__unused macro.

Test: gTest liblog-unit-tests --gtest_filter=\
      liblog.__android_log_write__android_logger_list_read:\
      liblog.android_logger_get_
Bug: 34250038
Change-Id: Ib33544171563d6a351164754c254c4385686025b
2017-01-26 21:13:31 +00:00
Mark Salyzyn 52c140ca72 liblog: add log/log_time.h
Move log_time definitions to their own home.

struct log_time

Test: gTest liblog-unit-tests --gtest_filter=liblog.log_time
Bug: 34250038
Change-Id: I400cf4cc865d1c167699a4654ecb69455a18e604
2017-01-25 15:41:43 -08:00
Mark Salyzyn c89fea44ac liblog: add log/log_radio.h
Move RLOG logging macros to their own home.

RLOGV
RLOGV_IF
RLOGD
RLOGD_IF
RLOGI
RLOGI_IF
RLOGW
RLOGW_IF
RLOGE
RLOGE_IF

Test: gTest liblog-unit-tests --gtest_filter=liblog.RLOG
Bug: 34250038
Change-Id: Iad5b5abf23c7a537ff5293bb55a6633dce2e837d
2017-01-25 15:41:43 -08:00
Mark Salyzyn dd61659e73 liblog: add log/log_system.h
Move SLOG logging macros to their own home.

SLOGV
SLOGV_IF
SLOGD
SLOGD_IF
SLOGI
SLOGI_IF
SLOGW
SLOGW_IF
SLOGE
SLOGE_IF

Test: gTest liblog-unit-tests --gtest_filter=liblog.SLOG
Bug: 34250038
Change-Id: I456c7ad23152dc1c7b39143d87401a8737e24d64
2017-01-25 15:41:43 -08:00
Mark Salyzyn 3cdbdd522f liblog: add log/log_id.h
Move common log_id_t and simple internal support function definitions
that use it from log/log.h to log/log_id.h.

log_id_t
__android_log_buf_write
__android_log_buf_print
android_name_to_log_id
android_log_id_to_name

Test: gTest liblog-unit-tests --gtest_filter=\
      liblog.log_id:\
      liblog.__android_log_buf_print:\
      liblog.__android_log_buf_write:\
      liblog.__android_log_buf_print__concurrent64
Bug: 34250038
Change-Id: Iad3704cc72943a3094e1193a6d032c7f29a6cd5c
2017-01-25 15:41:43 -08:00
Mark Salyzyn 5c967da341 ndk: reverse course on android/log.h
move LOG macros to log/log_main.h

move include/android/log.h to liblog/include/android/log.h

Test: compile of all components and gTest liblog-unit-tests
Bug: 34250038
Bug: 30465923
Change-Id: If182dd9b83689e8b7bc1a44b2f5d913c7ee5eeee
2017-01-25 15:41:43 -08:00
Vijay Venkatraman 651f8383e6 Revert "Revert "Exporting C headers from system/core""
This reverts commit a3f2be2b73.

Test: compile
Change-Id: I04b3a8e47e1fa3eb9d80c14ae3a90c68a780e858
2017-01-25 12:50:29 -08:00
Vijay Venkatraman 22b7f76a00 Merge "Revert "Exporting C headers from system/core"" 2017-01-25 00:53:07 +00:00
Vijay Venkatraman a3f2be2b73 Revert "Exporting C headers from system/core"
This reverts commit 3c6763ca21.

Change-Id: If3b3e106478d28a5df927d57649abdca0a99dd0e
2017-01-25 00:44:08 +00:00
Evgenii Stepanov f38ae34bbc Merge "Don't disable all sanitizers in liblog, just asan." 2017-01-24 23:00:54 +00:00
Evgenii Stepanov ffdabdc6f2 Don't disable all sanitizers in liblog, just asan.
ASan runtime library depends on liblog, so we have to disable ASan,
but nothing else.

Bug: 33091541
Test: SANITIZE_TARGET=address keeps working
Change-Id: I6e22925b7f1d5ec86fe1bd8c00dba4c3e86ddf3f
2017-01-24 12:57:23 -08:00
Vijay Venkatraman 3c6763ca21 Exporting C headers from system/core
Moved headers from include/libcutils and include/liblog to
libcutils/include and liblog/include respectively, so they can be
exported via these libs. They needed to be moved since Soong does
not allow export from external folder.

Added symlink from old locations. They are needed since Soong
includes system/core/include by default. Once all modules are
cleaned up to explicitly add the required libs, the symlinks will be
removed.

Also added liblog_vndk_headers that exports a special log/log.h for
VNDK.

Moved headers of libcutils to libcutils_headers. They should be used
by modules for header-only inlines. Added libcutils_headers as
dependency of libcutils.

Added libcutils_vndk_headers that exports a special cutils/log.h
deprecating usage of the file. A later CL will deprecate the one in
libcutils_headers

Test: Add above libs to shared lib of local module
Change-Id: I6e1f9c5f23d8b6eae13dc3b7e5dfe7fae93b8510
2017-01-22 19:45:38 -08:00
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