We may use different implementations of LogBuffer in the future, so we
make it interface and create a concrete ChattyLogBuffer class that
implements it.
Test: logging unit tests
Change-Id: I5731d6404640664c9acc26b7c677dff3110c6a11
There's still plenty of work that can be done here, particularly
re-doing the locking so each LogReaderThread does not mutually exclude
the others, but that's out of the scope here.
This change primarily removes the public 'mTimes' from LogBuffer and
creates a new LogReaderList class instead. It would have merged this
into LogReader, but that creates a circular dependency.
This change also removes the need to reference LogReader or
LogReaderList from LogAudit, LogKLog, and LogListener, instead relying
on LogBuffer()::log() to call LogReaderList::NotifyNewLog().
Test: logging unit tests
Change-Id: Ia874b57a9ec1254af1295bfa6f7af2f92a75755b
ThreadFunction() will only be entered once, so there's no worry that
we'll call prctl() multiple times.
Test: logging unit tests
Change-Id: Id2a02c2ab807f1565e3d625424e040481b3aa1a3
LogStatistics is intertwined with LogBuffer, even relying on it for
thread safety. This needs to change to have a proper
LogBufferInterface, so this CL separates them. Specifically:
1) Adding a lock to LogStatistics and adding thread annotations to
ensure that data structures are protected appropriately.
2) Moving prune_rows calculation into LogStatistics so it is done
while holding this lock.
3) Using LogStatistics instead of LogBuffer where appropriate.
Note that there should not be a significant performance regression
with this lock, as it will almost always been uncontended. If
anything, it should alleviate pressure from LogBuffer's lock.
Test: logging unit tests
Change-Id: I9d6dde2c96c9f024fa0341711c7bc63379e8e406
LogStatistics relies on LogBuffer's lock for thread safety, but that
will be cleaned up in future CLs. It won't be possible to return a
'LogFindWorst' object that references internal LogStatistics pointers
in a thread safe way, so we remove this and provide a more simple
interface.
This also removes unnecessary allocations; std::array of 2 or 32
entries is small enough to allocate on the stack.
Test: logging unit tests
Change-Id: I38bfcba5b08c640ffd3af5c078bc716688f6edf8
LogListener uses the libsysutils SocketListener class to read incoming
log messages, which means that it poll()'s to wait for new data then
calls recvmsg() when this data is available. That is unnecessary,
since this is a blocking socket, it already has a dedicated thread,
and we're not using any other SocketListner features, so a tight loop
of recvmsg() is sufficient.
Below are the stats from simpleperf during a framework restart. To
get an apples to apples comparison, these stats calculate the overhead
of receiving the message as 1 - (<number of perf events dispatching
the logs in logd>/<total number of perf events for the listener thread>).
With SocketListener / poll()
378563153 total events for the listener thread - SocketListener::runListener()
245799364 events for reading and dispatching logs + recvmsg() - LogListener::onDataAvailable()
67622952 events for recvmsg() inside LogListener::onDataAvailable()
=> (378563153 - 245799364) = 132763789 SocketListener + poll() overhead
=> (132763789 + 67622952) = 200386741 total overhead to for recvmsg() + poll() + SocketListener
=> (200386741 / 378563153) = 52.9% overhead to read each log message.
Without SocketListener / poll()
324802401 total events for the new listener thread - LogListener::ThreadFunction()
133208105 events for recvmsg()
=> (133208105 / 324802401) = 41% overhead to read each log message.
This shows a 22.5% = (41 - 52.9)/52.9 reduction in cost spent for each log message.
Test: logging unit tests
Test: simpleperf
Change-Id: I1f93b7a06fac6adce8e64e727bf6d8c5935c77c9
This is the last isMonotonic() user and can go away. This timestamp
is set in the kernel source in either the audit_get_stamp() or
__audit_syscall_entry() functions. In both cases, the value used is
from ktime_get_coarse_real_ts64(), which is a realtime timestamp.
Test: audit messages show in the log correctly.
Change-Id: Ife6c09dd97fccdfc7a8f07ee63161079ae2eccc4
This has been around for ~5 years but there has been roughly no
adoption, so remove this as we clean up the logging code.
Future efforts may track the monotonic timestamp in all cases.
Test: logging unit tests
Change-Id: I55ed565669f923988e741f6b384141bba893630d
1) We can use real member functions with std::thread and
std::function, so use those instead of the 'me' pointer.
2) Don't expose member variables directly.
3) Rename and document member variables, since all of their references
are being touched anyway.
Test: logging unit tests
Change-Id: I9a357a3ea8691433d58687c95356b984b83e9c36
LogTimes has evolved from being simply a store of the last timestamp
that each reader has read to being a class representing an individual
reader thread, including the thread function, so name it
appropriately.
Test: logging unit tests
Change-Id: I6914824376a6ff1f7509e657fa4dc044ead62954
This code has evolved to the point that it LogReader::notifyNewLog()
executes FlushCommand on every socket. FlushCommand then iterates
over all log reader threads in LogTimes and flushes triggers them to
flush logs if they match the client. This can be simplified to simply
looping over all of the reads in LogTimes.
Code readability was the primary motivation here, but note that 64% of
LogReader::notifyNewLog() was spent looping over the sockets, and an
additional 78% of FlushCommand::runSocketCommand() was spent
repeatedly locking and unlocking the LogTimes lock.
Overall, this reduces the cost of LogReader::notifyNewLog() in
LogListener::onDataAvailable() from 5.91% to 2.93%. This is the
critical path for handling incoming log messages, so it's a
non-trivial savings.
Test: logging unit tests
Test: unprivileged clients still cannot view privileged logs
Change-Id: Ic7620978a6c23e5e2cb179ff0c42b7cea52fc011
I added mOldest recently before mentally committing to have new code
follow the Google C++ style guide.
Test: build
Change-Id: I6d5bab5833e14ac3808862598a2a60989d805e18
logd needs a pointer to PruneList, but it should not own it and it
should not have initPrune() or formatPrune() functions.
Test: logging unit tests
Change-Id: Id1668c26d07eb5d1e4cf267f5748c20a79f711ae
It doesn't look like there are any users, since there is a much better
mechanism, `logd --reinit` that exists for this behavior. The
settings app and init.rc use that mechanism and they are the two major
clients that force logd to reinitialize.
This saves us from creating a thread and marginally cleans up
main.cpp.
Test: log reinitialization works
Change-Id: Icdb56b6f59adbba82812231a4f3a6ffd1a7955fc
LogBuffer needs a pointer to LogTags, but it should not own the
instance. It should not provide accessors into LogTags either.
Also, clean up CommandListener a bit.
Test: logging unit tests
Change-Id: Ic0c86a2bac0c4dd80262278588b9fdc2326dbe5b
This code was duplicated throughout LogBuffer.cpp, so refactor it into
a single location and clean up some comments along the way.
This may fix a subtle bug: if `logcat -c` is used from a
non-privileged UID, the current code may set mLast to the oldest seen
log message *from that UID* and not not the oldest log message for
that log id. That may prevent pruning from the start of that log,
resulting in old log entries that are impossible to delete.
Bug: 144382260
Test: logging works, and above scenario is not seen
Change-Id: I1749293ce6ea1697dd8a9258cfd7eab29dbeac6e
This test is repeatedly seen to be flaky. Disable it until we can run
tests against a dedicated logd instance.
Bug: 155146087
Test: logd-unit-tests
Change-Id: I0cd953955f613e40d17df73f70543d7d2f0925b6
log/log.h primarily concerns itself with writing logs. The few users
who read logs should directly include log/log_read.h.
Bug: 78370064
Test: build
Change-Id: Ie95c55ea2ffc76fc95768323d445ada6ad4f2520
This reverts commit 3614a0c5d4.
The original commit was added to check if what should be impossible
cases were happening. In the years after it was added, it doesn't
appear that these cases have happened. Recent reverts removed the
commits that caused the paranoia in the first place, making these
cases even more impossible.
Test: logging unit tests
Change-Id: I687c4d7876a38485e940f004dbd5ae6a1e15fb4c
logger_entry has a hdr_size field meant for backwards compatibility,
however there are a few checks that expect it to be a specific size.
More problematically, it has a variable length array element, msg[0]
at the end, that would be incorrect if the header size was not kept
static.
This change fixes up those issues to facilitate future additions.
Bug: 119867234
Test: logging works with extended size headers, logging unit tests
Test: newly added unit tests with extended size header
Change-Id: I14b2b0855d219d11f374b53a5aa8e05cd6a65eef
Logs in logd's buffer are not in time order.
If a client connects and requests logs from a given timestamp, we
start at the beginning of the buffer and find the first entry that has
happened since that timestamp and use its sequence number to flush
logs from. This ensures that we get all logs accumulated in the
buffer since that time stamp and not just the most recent.
However there may be other logs in the buffer that happened before the
timestamp and have likely been already served to the client, therefore
we do not flush those.
We only do this for the first flush, since once we have flushed all of
the logs in the buffer, if another log comes in with a timestamp
earlier than the requested timestamp, it must be out of order and not
seen yet, since it is new even to logd.
Note! This is still broken. There is a race that logs before the
timestamp may come in out of order since the last time the client
disconnected and before it reconnects. The *only* solution to this
problem is that clients need to request logs after a given sequence
number. That will be done as a separate liblog API change, while
these changes put in the ground work to make that possible.
Note 2: the security log implementation, which is one of the most
important users of this, already captures logs from seconds before the
last previous log to work around issues with timestamps. That
workaround mitigates the above issue.
Test: logs work with logcat -t
Change-Id: If1a62a90c082d98c4cf2eb5c92ae3b7e89850cf2
This reverts commit 5a34d6ea43.
There is a long standing bug that logd will leak memory during its
prune process if the time on the device changes significantly forwards
then backwards. This is due to using the timestamp of each log
message to determine what log messages are yet to be processed by a
reader thread.
Various attempts have been made to rectify this, but the only solution
that safely fixes this issue is to go back to using sequence numbers
on the log messages.
Bug: 64675203
Bug: 77971811
Bug: 149340579
Bug: 150923384
Test: logcat output looks sane
Change-Id: Ibce79cf184eb29a4914f3e42a8cb2868d04dc165
This reverts commit 0878a7c167.
This is a partial revert of the above commit. It simply removes
pruneMargin from these calculations since it is going away.
Bug: 149340579
Test: --clear works well
Change-Id: I1763be56fae7052058a800fad3b295c73cdcadf6
There are well known issues with CLOCK_REALTIME jumping drastically.
Test: --wrap works successfully
Change-Id: I5676274783ac9aa9374d2b9254e0109d883cc5a8
This reverts commit 5e001776f4.
The next commit will use CLOCK_MONOTONIC for the timeout, so changes
to CLOCK_REALTIME will no longer be an issue.
Test: logcat output looks sane
Change-Id: I84e5b2db3c25ea6a7024557dba7fa6cc8c9237e5
Sorting does not work in all cases:
* It only sorts messages up to 5 seconds backwards in time
* CLOCK_REALTIME, which is used as the time that is sorted, can jump
drastically
* Buffers are not sorted if there is a reader holding a region lock
Removing sorting entirely will give more consistent behavior from
logd.
Test: logcat still seems sane
Change-Id: I0923ab2fb377cda941c1e4972689df46f395ac99
The tests are only needed in vts10 suite.
Bug: 151896491
Test: local build
Exempt-From-Owner-Approval: This CL removes vts10 tests from vts suite.
It won't change test logic or behavior.
Change-Id: I4d468be075b54213b56c7e1aa94af94f2bdce9ff
This is to prepare renaming vts to vts10.
Bug: 151896491
Test: local build
Exempt-From-Owner-Approval: This CL adds all tests in vts to a new
suite vts10. vts10 will be the new name of existing vts suite. This CL
won't change test logic or behavior.
Change-Id: I3c7ccef142de30f02a59046cecba121480f6e436
This buffer isn't human readable and the parsers aren't set up to
handle the 'chatty' message for identical log messages. Further, it
is a low volume buffer so there's not much in terms of memory saving
if this were enabled.
Bug: 137093665
Test: security unit tests
Change-Id: I03fce518d3308a6d9240bd29e83ff3237203fe3b
This is renamed to ro.organization_owned to cover the extended
usage now that there is a new management mode for fully-managed
organization owned devices: organization-owned managed profile.
A device is considered fully-managed if there is a device owner
or an organization-owned managed profile.
Test: atest liblog-unit-tests
Test: atest propertyinfoserializer_tests
Bug: 148437300
Change-Id: Iaa8ea246c973732526abc1da5b307af8bce1a0af
Incidentd needs to access /data/misc/logd to get persisted logs for
debugging purposes. Relax permissions on /data/misc/logd to allow
group (log) to access the dir and read its files. Effectively change
to:
drwxr-x--- logd log /data/misc/logd
-rw-r----- logd log /data/misc/logd/logcat*
Since this dir stores the past output of logcat, anyone that can run
logcat can be granted access to this dir. Access to this dir is further
guarded by SELinux. So it is safe.
Bug: 147924172
Test: Build, flash, reboot. Verify that the files have the right
permissions.
Change-Id: I4d2aa9d5883d1ef14411b2b3902f0ca7c641dd7e
Marks this CTS test module as supporting secondary_user, meaning that
the tests are eligible to be run from a regular Android user other
than the system user (i.e. other than user 0).
Note that 'user' here refers to the concept of users in Android
Multiuser; it is NOT the same as a uid.
Bug: 141773058
Test: module passed with secondary_user params
(--enable-optional-parameterization --module-parameter secondary_user)
Change-Id: Ic1c3c5f86e0178c8e3e2ec8c3d3069ecd9e580e9
package_string() isn't readable in its current form and a loop is
unnecessary, so let's replace that with the direct calculations. The
new and old functions are identical in results except an edge case
where the old function incorrectly believes it needs to round up to
'10' for the size prefix, when '9' would be ok, specifically:
10\naaaaa\n\f vs 9\naaaaa\n\f. This is true for all powers of 10.
Clean up the calling side in logcat as well.
Test: printing log statistics and prune list works
Change-Id: Ib62ab2badab59040215b130ec9e3efbc7c95af3f
We're kicking logcat clients more frequently than expected, so print
this information for debugging purposes.
Bug: 144311420
Test: see these logs
Change-Id: I1570cd4b377a62c863bc26c7b3148e04c2433a9c
* changes:
liblog: document the liblog<->logd protocol format
liblog: remove unused parts of android_log_transport_context
Remove old logger_entry_v* formats
liblog: disable header_abi_checker
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
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
logd currently only reports the UID of a log message for 'privileged'
readers (those with a uid or gid of root, system, or log). However,
UIDs are not particularly sensitive. Much more importantly,
non-privileged readers can only see less messages from their own UID,
so this restriction is essentially a no-op, as those readers will
already know their own uid.
Test: liblog and logd unit tests
Change-Id: I9da7d15eb840ba3200128391e70d618eec79f988
