Commit graph

636 commits

Author SHA1 Message Date
Tom Cherry
06e0fced63 liblog: have writers handle their own state
Remove the transport available and open functions since the writers
are able to manage their own state.  Remove the initialization dance
with write_to_log, since it is unneeded once this is removed as well.

Remove the global lock around the close() functions as correct locking
has been added to the writers in a previous change.

Test: logging works, liblog-unit-tests
Change-Id: If7fa11e773763d0b5fcb2e696ad1c88ff4a4cfdf
2019-12-12 16:19:08 -08:00
Tom Cherry
2a6811b4d1 liblog: use a rwlock for writer initialization
The current system of using atomics isn't thread safe and may result
in doubly closing FDs or closing actively used FDs.  The safest way to
do this is to use a rwlock, which should not have a much higher
overhead than the atomics do, as a vast majority of the time, there
will not be writers.

This moves us further away from using the transport interface, which
will be removed.  Each writer should be self contained, without a
separate open or available function.

Also, keep the pmsg fd open if it is opened by
__android_log_pmsg_file_write().  This fd was closed due to issues
with zygote, but it looks like it is only called by recovery now, so
there is no reason to close this fd at the end of that function.

Test: logging works, liblog-unit-tests
Change-Id: I345c9a5d18c55b11a280c8362df854784abf46fd
2019-12-12 16:19:08 -08:00
Tom Cherry
49a8af7dff liblog: do not check loggability of event logs before sending to logd
This code was introduced to help performance by skipping sending these
messages to logd when logd would later drop them.  However it has
multiple flaws:

1) Event logs aren't super common and non-loggable event logs are even
   less common, so it would be a trivial benefit if any.
2) This code is not particularly safe as written, which is even
   acknowledged in the comments.
3) This forces processes that write event logs to allocate a rather
   sizable amount of memory.

Therefore, it's better to simply remove this and let logd drop these
messages when it receives them.

Bug: 139705697
Test: logging works, liblog-unit-tests
Change-Id: Ide01574112e173d4922137b3d3868cf8c2c09086
2019-12-11 15:46:47 -08:00
Tom Cherry
c619e49f74 liblog: simplify fake_log_device
This still fakes the long removed /dev/log devices, whereas it only
needs to print to stderr, so simplify that code.

Use std::mutex now that it is C++ to easy portability concerns.

Use the proper liblog headers for formatting information instead of
hardcoding a copy.

Test: liblog-host unit test
Change-Id: I310a6e7ad939960300eafa729cbfc535c5ced445
2019-12-11 07:20:37 -08:00
Tom Cherry
d953ba3c82 liblog: add a test for liblog on host
Test: this test
Change-Id: I60fa8b82dbc010395762eba70502b89b295e29f5
2019-12-10 15:35:19 -08:00
Tom Cherry
ed860ff4bf Make android_logger_set_prune_list() sane
The current version requires callers to supply a string with 32 extra
bytes for liblog to internally prepend "setPruneList ", and to have
enough space to parse logd's return string.  That is an unacceptable
requirement on callers.

This change removes that requirement by having liblog allocate the
needed std::string in any case.

It also stops writing back the 'success' or 'Invalid' string to the
caller's buffer, since that is redundant as well.

Test: changing prune settings works.
Change-Id: Ic0f03a229f0b9a77d03adcb91288370c3bd42903
2019-12-06 11:23:58 -08:00
Tom Cherry
8d2225353c liblog: accept log messages with hdr_size greater than known headers
We don't need to be so strict about this comparison.  It's possible
that logd will extend the message that it passes to readers in the
future, and since we have a hdr_size parameter it can do so in a
backwards compatible way, as long as we loosen this restriction.

This keeps a sane upper bound that the hdr_size cannot be larger than
the log message itself.

Test: logcat, liblog-unit-tests
Change-Id: I8a6bea2a2d6e3315d998c51c1029e466ff06b45f
2019-12-04 15:28:03 -08:00
Tom Cherry
4023938914 Merge "liblog: remove the rest of the log reader transport" 2019-11-19 20:21:42 +00:00
Tom Cherry
332f99a7ed Merge "liblog: remove memset() before recv()." 2019-11-19 19:31:06 +00:00
Tom Cherry
1a75a8cd4b liblog: remove memset() before recv().
This is unneeded, since we're already checking the length returned by
recv() and log_msg that is read for validity.

It costs ~4% of CPU with `logcat -s` and ~2% of CPU when running
simpleperf for 1 second on walleye on master.

Bug: 144311420
Test: logcat works, simpleperf doesn't show memset() costing as much.
Change-Id: I986e7e96518774034340f1b1201a2071a904e3bb
2019-11-19 10:10:37 -08:00
Tom Cherry
026ddde6e4 liblog: remove the rest of the log reader transport
This is simplified down to the point there are only two branches that
need to be made, so remove the rest of the transport structs and
simply branch where needed.

Test: liblog-unit-tests
Change-Id: Ic82e7e70eb7b4e40b381a4d8066629c5b7d4f827
2019-11-19 09:41:49 -08:00
Greg Kaiser
9829e7f894 liblog: Assure shifting behavior is consistent
Shifting a signed 32-bit value by 31 bits is implementation-
defined behavior.  So we change to an unsigned value for our
shift by 31 bits, and go ahead and change the others to
unsigned for consistency.

Test: TreeHugger
Change-Id: Ib98f9b1e468d28dafd09e86273bf76beb1ea1fa5
2019-11-19 06:53:22 -08:00
Tom Cherry
7d16aedc47 Merge "liblog: simplify logd 'command' functions and struct logger" 2019-11-18 21:47:16 +00:00
Tom Cherry
9156c534e0 liblog: simplify logd 'command' functions and struct logger
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
2019-11-18 07:16:40 -08:00
Tom Cherry
c9c8318db6 Merge "liblog: return 0 from android_logger_list_read() when recv() returns 0" 2019-11-18 14:37:54 +00:00
Tom Cherry
b8bacea818 liblog: return 0 from android_logger_list_read() when recv() returns 0
We used to do this, but it got lost while refactoring this code.

Bug: 144311420
Test: we see "unexpected EOF!" instead of "unexpected length" from logcat
Change-Id: I7858d0a774a9eac63e5547ee67e85ef8fb0c682d
2019-11-15 16:48:01 -08:00
Tom Cherry
828db1a901 liblog: cleanup opaque type usage
There's a lot of unnecessary boilerplate around these opaque types,
and this change simplifies it.

Test: liblog-unit-tests
Change-Id: I0c4e133037fd5f04157ac22175181a6a496e18c4
2019-11-14 10:40:42 -08:00
Jiyong Park
b2542d2942 Rename # vndk tag to # llndk
The APIs that are tagged with # vndk are actually for LLNDK libraries.
Although LLNDK is part of VNDK, calling those APIs 'vndk' has given
users a wrong perception that the APIs don't need to be kept stable
because that's the norm for most of the VNDK libraries that are not
LLNDK.

In order to eliminate the misunderstanding, rename the tag to 'llndk' so
that people introducing new such API will realize what they are signing
themselves up for.

Bug: 143765505
Test: m
Merged-In: Iae2acdf1ff4097a64a5c6280797c66abb1d5a5e6
(cherry picked from commit 0e957b82c8)
Change-Id: Iae2acdf1ff4097a64a5c6280797c66abb1d5a5e6
2019-11-13 14:32:44 +09:00
Josh Gao
594f70ffb8 Move adbd to an apex.
Test: adb shell "su 0 readlink /proc/\`pidof adbd\`/exe"
Change-Id: I84dfe4d1b28b619f98c03a2c8eeef2c783d30af2
2019-11-04 15:52:16 -08:00
Tom Cherry
a379b1ce05 liblog: document the liblog<->logd protocol format
This protocol documentation is spread out among various functions
where it is implemented.  This change makes a single
README.protocol.md file with a high level overview, referencing the
struct names where useful.

Test: n/a
Change-Id: I83c9f484352b489b4a20cce241d92413f780f9ec
2019-10-24 11:19:06 -07:00
Tom Cherry
e05b78412b liblog: remove unused parts of android_log_transport_context
Neither logMsg nor ret are needed in this struct anymore.

Test: build
Change-Id: Ic75158153767dd57d56a71b551a2b106cbdab6d7
2019-10-24 10:53:14 -07:00
Tom Cherry
441054aa1e Remove old logger_entry_v* formats
logger_entry and logger_entry_v2 were used for the kernel logger,
which we have long since deprecated.  logger_entry_v3 is the same as
logger_entry_v4 without a uid field, so it is trivially removable,
especially since we're now always providing uids in log messages.

liblog and logd already get updated in sync with each other, so we
have no reason for backwards compatibility with their format.

Test: build, unit tests
Change-Id: I27c90609f28c8d826e5614fdb3fe59bde22b5042
2019-10-24 10:53:14 -07:00
Tom Cherry
896fb9e57a liblog: disable header_abi_checker
I'm about to make a bunch of changes that are safe for backwards
compatibility, but would otherwise flag the checker, so it's time to
temporarily disable it.

Test: CLs pass despite making header changes
Change-Id: Ibc2d4ae51fb8e6125b9117ccd92bf821db945e67
2019-10-24 10:52:25 -07:00
Tom Cherry
350164cc7c Revert "liblog: remove mistakenly added symbols from vndk"
This reverts commit 5f8162b086.

Reason for revert: Turns out they're being used.

Merged-In: Iad9010190c7a4140b69dc553df5debdd88dcf81a
Change-Id: Iad9010190c7a4140b69dc553df5debdd88dcf81a
2019-10-23 11:39:13 -07:00
Tom Cherry
7867721e51 liblog: remove mistakenly added symbols from vndk
These functions and headers were all mistakenly added to the vndk.
They should not be used by vendors.

Test: these symbols do not appear in vendor libraries
Merged-In: I03919b437c2d9f0e573b7a6b40249ed12fe874b9
Change-Id: I03919b437c2d9f0e573b7a6b40249ed12fe874b9
2019-10-22 09:47:45 -07:00
Tom Cherry
5e81aa2cf5 liblog: fixup log_id_t
1) We don't need two copies of log_id_t
2) We don't need misleading sizeof_log_id_t or typeof_log_id_t macros
3) logd should use android_log_header_t explicitly for its recv buffer
   size
4) Following on from b/129272512, we're settling that returning
   LOG_ID_MAX is an acceptable return value from
   android_name_to_log_id().

Bug: 129272512
Test: build, liblog, logcat unit tests
Change-Id: I67fb964a4a0ae9cb6e1514ca110e47e00dfcfa9a
2019-10-18 09:58:08 -07:00
Tom Cherry
362e289c78 liblog: remove checks for __GNUC__
We already assume this in many other parts of the build.

Test: build
Change-Id: Ie685e83963eac942d0d176bb2394b5d3a5b86cac
2019-10-16 17:14:39 -07:00
Tom Cherry
443b5dfea7 Merge "liblog: remove client side permissions checking" 2019-10-16 13:57:41 +00:00
Tom Cherry
fa88eeb95e Merge "liblog: remove unneeded checks and includes from headers" 2019-10-16 13:51:42 +00:00
Tom Cherry
1e59dcc203 liblog: remove client side permissions checking
There's no point in client side security checks in this library.  If a
process has access to these files, then they'll be able to do any of
these operations themselves.

Test: liblog unit tests
Change-Id: I75d4e1509eb8ff0ac4579f820a8968f4f5ad4e06
2019-10-15 16:06:06 -07:00
Tom Cherry
3ab3135bba liblog: enable more tests
Enable more of the disabled tests.  These should not be flaky and have
value.

The dual_reader test is rewritten in the style of RunLogTests() as
well.

Test: 100 iterations of these tests on CF without failure
Change-Id: I15de9e21b066aa22635cc0bd71b51e2648198823
2019-10-15 11:15:53 -07:00
Tom Cherry
f5bad500f3 Merge "liblog: remove obsolete comment" 2019-10-15 14:48:05 +00:00
Tom Cherry
c734eae375 liblog: remove unneeded checks and includes from headers
Test: build
Change-Id: Ifa3cffe60120fcc30a37239ceb2db46202a03471
2019-10-14 16:11:12 -07:00
Tom Cherry
4e58c84854 liblog: remove obsolete comment
The log_time struct satisfies all of the requirements for an
implicitly created copy constructor to be present, so not defining one
here does not have any real effect.

We don't want to delete the copy constructor for the rationale given
either; modern C++ favors passing small types by value instead of by
reference as the compiler has more opportunity for optimization in
that case.  That's especially true here, where the size of this struct
is the size of a pointer on 64 bit systems.

Test: the copy constructor exists for log_time
Change-Id: Id314ca7729f4b1ca02adb6c7f0ae759b22be2a5c
2019-10-14 13:23:29 -07:00
Tom Cherry
c6a427205d liblog: use RunLogTests() for more tests
Continuing the speed up / clean up from the last change.

Enable a subtest that was previously disabled as well.  It passes 100s
of cycles now on CF.

Test: liblog-unit-tests
Change-Id: Ifff6f400c3736a1a857a3fdaf22d7ef1794abf9b
2019-10-14 13:11:26 -07:00
Tom Cherry
dbc4815dbf liblog: don't sleep in the middle of tests
A lot of liblog tests follow this pattern:
1) Write a log message
2) Sleep ~1 second
3) Use the non_blocking log reader to dump all log messages
4) Test those log messages

This causes running back to back tests to be very slow and still
allows for some amount of flakiness if the system is very loaded.

This change replaces that pattern with the following:
1) Write a log message
2) Set an alarm for 2 seconds as a test timeout
3) Read logs with the blocking reader until finding the expected log
   messages
4) Test those log messages
5) Use the non_blocking reader to dump all log messages
6) Re-test those log messages, to ensure no duplicates, etc, which
   isn't done in step 3).

Despite dumping the logs twice, the tests are orders of magnitude
faster in the good case, and should be less prone to flakes.

Test: liblog-unit-tests
Change-Id: Iedf473316576b8007746fe3560815bde1813787a
2019-10-11 10:56:11 -07:00
Tom Cherry
bbbf089137 liblog: use packed structs instead of raw unaligned reads
Per jmgao@, we still need to worry about unaligned integer accesses.

In any case, we already have the packed structs for all of the
unaligned data that we're reading, so this change favors using those
packed structs.

Bug: 142256213
Test: x86,arm32,arm64 liblog-unit-tests
Change-Id: I21fc629eac49895d03b5b31daa4cc494b0c4c230
2019-10-09 18:20:49 -07:00
Tom Cherry
e3fc9ac7e3 Merge "liblog: remove alarm in logd_reader.cpp" 2019-10-09 14:48:38 +00:00
Tom Cherry
5398021b9e liblog: remove alarm in logd_reader.cpp
There is an alarm() call that provides a 30 second timeout in case
logd is unavailable.  The main reason for this is in the case that logd
is crashing, debuggerd is ptrace'ing logd, and tombstoned is
attempting to dump log messages.  In this case, with no other checks
and without this alarm, tombstoned will deadlock when dumping log
messages.

However, tombstoned already has two mechanisms to prevent the above
situation from happening:
1) It checks that the thread name that is is dumping is either logd or
   starts with "logd." and skips dumping logs in this case.
2) It does not dump logs if it is running in process for any process.

Calling alarm() or modifying signal handlers from general purpose
libraries is not recommended either, so without a strong reason to
keep this, this change removes it.

This also shortens the liblog.wrap_mode_blocks test time, since the 30
second issue that it ensures does not happen has been fundamentally
removed.

Test: `kill -8 `pidof logd`` succeeds without delay
Test: liblog, logd unit tests
Change-Id: Id8a40544645d220e49f7ba299201af80a0c44de9
2019-10-08 13:05:55 -07:00
Tom Cherry
5d7969b58a Merge "liblog: remove code checking for fd = 0" 2019-10-08 19:24:02 +00:00
Tom Cherry
29d0e89364 liblog: remove code checking for fd = 0
Fix a typo where I check socket()'s return value for 0 instead of -1
as an error.

Remove code that checks if socket() returns 0 as the actual fd that it
returns.  This should not happen in any well formed program.

Test: liblog unit tests
Change-Id: I1d878e85d9a39155d68c6c84e9cf9b0db8d1b3a4
2019-10-08 10:18:20 -07:00
Nick Desaulniers
34282df8bb [liblog] fix -Wreorder-init-list
Bug: 139945549
Test: mm
Change-Id: I57de1a650d2c85dfb4f8817bbc80eb2296eaf568
Signed-off-by: Nick Desaulniers <ndesaulniers@google.com>
2019-10-07 21:28:43 -07:00
Tom Cherry
7e99b22527 liblog: run in isolated mode, disable flaky tests
We disabled then re-enabled a set of tests believing that they were
stable; they were not, so we disable them again while we investigate
their stability.

A majority of tests filter the logs from logd based on pid, so running
in isolation helps them not see unexpected information from other test
runs.

Bug: 138876729
Bug: 142041379

Test: run via gtest with gtest_repeat=10 without failure
Test: run via atest 5x times without failure
Test: observe that isolated applies to both gtest and atest
Change-Id: I757d52dd3233323be9519625868b2fd2aaa41aeb
2019-10-04 13:05:50 -07:00
Treehugger Robot
c37e3f01ee Merge "liblog: use EXPECTED_STREQ for strings" 2019-10-03 18:40:32 +00:00
Tom Cherry
0de52e92dc liblog: use EXPECTED_STREQ for strings
These tests are flaky, but we're not seeing what the failure strings
are.

Bug: 142041379
Test: force a failure and see the right error message
Change-Id: Icd7777e5c309cac3b98ce65925980965a3cc3753
2019-10-03 07:32:24 -07:00
Tom Cherry
685949daad Merge "liblog: remove superfluous checks" 2019-10-03 13:58:35 +00:00
Tom Cherry
47fdf666fb Merge "liblog: don't set transports to nullptr when they close" 2019-10-03 13:58:09 +00:00
Tom Cherry
990852ff7d liblog: remove superfluous checks
More checks in static functions where all callers always satisfy them.

Test: build
Change-Id: I3c9bd1fd4e5c55a2f9f2c42d5259c5cdd8f8a853
2019-10-02 14:27:04 -07:00
Tom Cherry
97ec4eecd4 liblog: don't set transports to nullptr when they close
The old code did not free the transports, just unlink their nodes from
the linked list, so there was no race condition between close() and
other threads writing to the logs.  By settings these to nullptr, I
introduced a race condition, but setting them to nullptr isn't
necessary, so let's simply not do that.

Test: liblog-unit-tests
Change-Id: Iec0b680addd13b5d30bd91ccef5bdeab6bf797b0
2019-10-02 14:22:07 -07:00
Elliott Hughes
6efbda7309 liblog: replace crufty min macro with existing MIN.
The "branchless" macro generates slightly worse code than std::min or
<sys/param.h>'s MIN.

Test: treehugger
Change-Id: I92c17325383bd6116c7b4736d42f01f7a9bb81a3
2019-10-02 12:27:03 -07:00