Add a BM_log_verbose_overhead test that measure the overhead of
writing a log message that will not be printed due to verbosity
levels. This was optimized in R to not format the log messages before
checking if they will be logged.
Results with R:
BM_log_verbose_overhead_null_mean 159 ns 159 ns 100
BM_log_verbose_overhead_null_median 159 ns 159 ns 100
BM_log_verbose_overhead_null_stddev 0.568 ns 0.464 ns 100
Results with Q:
M_log_verbose_overhead_null_mean 601 ns 600 ns 100
BM_log_verbose_overhead_null_median 601 ns 600 ns 100
BM_log_verbose_overhead_null_stddev 2.40 ns 2.23 ns 100
This benchmark shows liblog's overhead when not printing a log message
to be nearly ~4x faster than with Q.
Test: run this benchmark
Change-Id: I09a60e61bf064330bf15a9d0a946acf16e777a6d
There are a set of functions, such as android_logger_get_log_size()
and android_logger_get_prune_list() that talk to the logd command
socket to perform their activities. There's a transport abstraction
layer that handles these symbols to optionally route them to other
transports, originally designed for pstore or local logger; however
these functions fundamentally only make sense for logd.
Ideally, these functions would be removed and new functions would be
added that do not depend on struct logger_list or struct logger and
more clearly indicate that they only work with logd. For example:
android_logger_get_size(struct logger*) could be
logd_get_buffer_size(log_id_t log_id). We would remove the need to
'open' the struct logger and make it clear that it only operates on
logd.
Since liblog is an llndk library however, we cannot change or remove
these symbols. Since these symbols are not frequently used, it seems
acceptable to keep them as is and not introduce improved versions.
We, however, do want to simplify the code that handles them and this
change removes the transport abstraction layer that handles them.
They retain the behavior that unless the struct logger_list was opened
for logd, that the functions return -EINVAL.
The one exception to this is android_logger_clear(). If the struct
logger provided to this function was opened from a struct logger_list
that used pstore for its mode argument, this function will clear the
entire pstore log. This function does not respect the 'logId'
parameter of the struct logger, since that would not be possible.
This change removes this android_logger_clear() behavior and makes it
strictly for logd, for symmetry with the rest of the functions and due
to the lack of clarity regarding the 'logId' parameter of its input.
The only caller of this function, logcat, will clear pstore directly.
struct logger was built to encapsulate the information needed to
connect to a logger device from the old kernel logger. Now that we
only support reading from pstore and from logd, there is much less
information needed to be captured. Specifically, we only need to know
the log_id and whether or not it was opened as part of a pstore or
logd 'list'.
Test: liblog-unit-test
Test: logcat -c/-g/-G/-p/-P/-S work
Test: logcat -c works with -L
Test: logcat -g/-G/-p/-P/-S continue to fail with -L
Change-Id: I2c549b6f8539de94510e223949ab209ecc40e2d0
There are no users; future versions will need to be more generic to
support the libbase style Logger/Aborter options.
Test: build, liblog-unit-tests
Change-Id: Ia4571cd39d3e499f18306920ecbf40ea8878fb81
socket_local_client() was copied from libcutils, but we only need a
small subset of its functionality. We instead create our own version
with just the needed parts.
Importantly, use CLOEXEC in this new function and other places where
it was missing previously.
Test: logging works, liblog-unit-tests
Change-Id: Ifb929227af67bafa13e391eab92358d9f6fe6450
readv() isn't used by anyone, writev() has one easily replaced user.
uio.h can be left as a private header for windows compatibility with
struct iovec.
Test: build
Change-Id: I33d4c6bdee6fd818271f78ae06abdd2aa09430f2
Add local BM_time_clock_gettime_*, BM_time_clock_getres_* and
BM_time_time benchmarks. Relates to the bionic benchmarks of
the same names, except adds CLOCK_MONOTONIC_RAW. Added here for
developer convenience whenever updates to the liblog or logd
code base need integration testing.
ToDo: add liblog gTests that analyse the benchmark data to confirm
that the specified integrated device has vdso access to all the
pertinent clock sources. Add liblog local benchmarks and tests to
measure the device clock drift of each possible liblog clock
source to help evaluate device configuration.
Test: liblog_benchmarks --benchmark_filter=BM_time*
Bug: 63737556
Bug: 69423514
Change-Id: Ibafe0880d976ef2b3885765f71e0ba6c99d56f2a
Remove our circa 2014 snapshot of the google benchmarking library, and
use the now very stable google-benchmark suite. Some porting effort,
and deal with some benchmarking saddle points that take too long to
sort out. Focus on minimal API changes, _odd_ new behaviors, and style.
Test: liblog_benchmarks, ensure results in about the same range
Bug: 69423514
Change-Id: I2add1df9cb664333bcf983b57121ae151b26935b
Measure the cost of using a known test event log tag from
system/core/logcat/event.logtags:
42 answer (to life the universe etc|3)
Test: liblog_benchmarks BM_log_event_overhead_42
Bug: 36683634
Change-Id: Ibd4be82bebfcedd381c84e8078cf6d05a636aa98
We still do not have any users of the 'frontend' interface, let's
right a wrong and rename it to 'transport' as it makes more sense.
Renames android_log_set_frontend, android_log_get_frontend and
include/log/log_frontend.h.
SideEffects: None
Test: gTest liblog-unit-tests
Bug: 27405083
Change-Id: I7c1c0f3dfdc7cf047285403e306edbd16ad1324d
Additional benchmarks to check the effects and performance of the
frontend changes.
Test: manual liblog-benchmarks
Bug: 27405083
Change-Id: I2a9dba81b70e9d71cdb8de1b35e8dff099ad6038
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
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
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
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
Always used in combination with log/logger.h except in log_time.cpp,
and not used externally. As a result liblog has to support stl, a
small price to pay since goal is to convert liblog to C++ internally.
Test: compile
Bug: 31456426
Bug: 26552300
Bug: 31289077
Change-Id: I72828ec807d0a2c8e40bbdebd7a69f147a7ca5a9
- check hdr_size to make sure it is in the expected range
from sizeof entry_v1 to entry (entry_v4).
- alter msg() method to report NULL on invalid hdr_size
- alter all users of msg() method.
Bug: 30947841
Change-Id: I9bc1740d7aa9f37df5be966c18de1fb9de63d5dd
- Deal with __android_log_is_loggable inside signal handler by
treating a lock contention system call as more costly than reading
the associated property directly. Rather waiting around in a
contended stat to hit cache.
- Check both the individual known __system_property_serial() and
global __system_property_area_serial() to detect updates or
additions to the properties to respond in the most aggressive and
timely manner. __android_log_is_loggable() return at max CPU
clockrate on a N9 in 61ns.
- Craft a common do_cache2 inline that adds the above to the other
functions that utilize cache handling and preserves (within 3ns)
performance in android_log_clockid() and __android_log_security().
These functions return at max CPU clockrate on a N9 in 23ns.
Bug: 19544788
Bug: 25693940
Bug: 25792367
Bug: 26178938
Change-Id: I9cd94598f5c558e946b93977ad3714a4b03d0422
This test tells us that scatter-gather (writev instead of write)
carries a small ~2% penalty. Unaligned buffer carry a similar
additional penalty. On N9 it takes 3us to 22us _just_ to write
the pmsg logs, depending on size. Some assumptions about the
socket read and write performance for the main logging can be made
from tracking these results and should improve design decisions.
Bug: 18771697
Bug: 23685592
Change-Id: Id4d64c449140e4f39078c62b0097e403df91fe0c
- On a N9 64-bit benchmark, the __android_log_is_loggable overhead
is roughly 500ns (1/2 of a syscall?)
Bug: 19544788
Bug: 17760225
Bug: 20416721
Change-Id: Ib9e4d06d96e1b19ca5d459e569ead451ef47a9c0
Move away from using POSIX open(2) flags and introduce ANDROID_LOG_* flags to
replace them. Add security by preventing random mode flags from getting into
underlying POSIX calls. ANDROID_LOG_* flags overlap POSIX O_* flag definitions.
Change-Id: Ib32bb64c287e8bf150be62242e1ba46bb37839fc
- structure packing
- move towards log_time from struct timespec
- extend log_time to cover differences between
log_time and struct timespec
Change-Id: I106ed0b609917306d170044054b5b32645f2a295
