logd suffers performance degradation when multiple blocking
readers connect to it. Each time when the writer thread log
new entries, all of the readers are notified regardless of
which log id they are watching.
In this case, only give notification to the readers who are
actually watching new entries' log id. This decreases logd
CPU consumption by skipping unnecessary LogBuffer::flushTo
loops.
Test: liblog-unit-tests, logd-unit-tests & CtsLiblogTestCases
logcat-unit-tests
Test: manual:
1.'logcat –b all' at constant heavy logging load level
2.simultaneously 'logcat –b crash' in another session,
a healthy crash buffer usually keep empty
3.logd CPU consumption doesn't increase after step 2
Change-Id: I4ffc045c9feb7a0998f7e47ae2173f8f6aa28e8a
Now that creating a symlink in init automatically sets its
context, we do not need to call restorecon manually.
Bug: 69965807
Test: Booted device and tested wifi and camera.
Change-Id: I0863198f2c2bfce79566b5320c7ef035698f3afb
Fix for buffer overrun when a tag that is too big is sent to logd.
Buffer supplied is precisely the right size for max message length
however strlen will be run on the buffer, so need to ensure null
terminator, otherwise any strlen will go off the end of the buffer.
Also converted LogBuffer::Log() over to use the safer strnlen in the
case where it is measuring the buffer (and converted over to using
__android_log_is_loggable_len())
Signed-off-by: Paul Elliott <paul.elliott@arm.com>
Test: liblog.android_log_buf_print__maxtag
Change-Id: I3cb8b25af55943fb0f4658657560eb2300f52961
See https://lkml.org/lkml/2005/9/10/129 for details.
Bug: 20501816
Test: code compiles and boots with no obvious problems.
Change-Id: I5a9c470156d498852cfd81fbd59ddcf267309e73
Cts tests can run in appdomain, which have access to /data/backup/
which leads to zero injection of sepolicy signal to check the logd
and kernel rate limiter. Switch to /data/drm/ as a better choice
to inject a sepolicy denial either due to dac_override or
dac_read_search because owned by the drm uid and gid, or due to
create sepolicy denial to u:object_r:drm_data_file:s0 to all but
select services.
Test: gTest
Bug: 65843095
Change-Id: I2d72b1407a930c270636a206066d2d15fdec2f77
SELinux messages weren't properly filtering into the events buffer
because message_len was being used to determine length of event data
instead of str_len
Bug: 65597269
Test: SELinux denials show up in the events buffer
Change-Id: I857e10211f71dd0db33a272241c7051c5d0c59ca
liblog concurrent printf tests now check every write succeeds.
logd timeout_negative tests exits as soon as one run succeeds.
Test: CTS tests till pass.
Change-Id: I9a166a0abcb8b9aa5c055c35c5dccf30616a4e24
The feature references a new file created by the selinux make system
that is stored on device under /system/etc/selinux/ which contains a
scontext, tcontext, tclass, and the bug they map to. logd will
reference this map every time an selinux denial comes through to see if
it's a known denial with a bug attached and then add the bug number to
the denial that's logged.
go/selinux-bug-metadata
Bug: 34997782
Test: any denial -> bug map listed in the referenced file is correcty
displayed in the selinux denials that are logged
Change-Id: I75bab59917591ed700471a0b4922b5f02f86bee9
- Remove virtual from the destructor.
- Remove mTag and derive it when calling getTag().
- Add a boolean mDropped to tell when a message is dropped.
- When dropping a message, and it contains valid tag data, reallocate
the message to only contain the tag data.
- Add the packed tag to the class.
This saves about ~150K of PSS on a typical log stream since it moves the
size of the LogBufferElement from 48 bytes to 32 bytes which puts it in
a smaller bin.
Bug: 63792187
Test: Builds, unit tests pass.
Change-Id: Ia5afce343ea3d344fcecd78c648338e94f5c9312
The get4LE method needs to use unsigned types since the sign char values
can lead to producing wrong values.
Bug: 62599757
Test: passes all test cases of logd-unit-tests.
Change-Id: Ifaf83533d847ea4fbe0cd46a978f4dabbfa7df8d
We have already searched for the start point, the start filter check
is paranoia that removes out-of-order entries that we are undoubtably
interested in. Out-of-order entries occur under reader pressure, as
the writer gets pushed back from in-place sorted order and lands it
at the end for the reader to pick it up. If this occurred during a
batch run or a logger thread wakeup, the entry could be filtered out
and never output to the reader.
We have to treat exact finds for start in the list as terminal when
we search as they represent restarts, depending on the fact that it
is impossible to have the exact same time reported in two log entries
or requested from a batched reader. This does break down if a log
entry has xxxxxx000 nanoseconds reported, we fix that by making sure
we never log such a case and slip it by a ns.
Found one case where logcat.tail_time* tests failed which was fixed
with this adjustment.
Test: gTest logd-unit-tests, liblog-unit-tests and logcat-unit-tests
Bug: 38046067
Bug: 37791296
Bug: 38341453
Change-Id: I4dd2e2596dd67b8d602160dd79661e01805227a9
Regressed by introducing too much overlap in the results.
This reverts commit 982ad208b5.
Bug: 38341453
Change-Id: I9d630a6b9f3e464f523424b640090f7e268da9bd
We have already searched for the start point, the start filter check
is paranoia that removes out-of-order entries that we are undoubtably
interested in. Out-of-order entries occur under reader pressure, as
the writer gets pushed back from in-place sorted order and lands it
at the end for the reader to pick it up. If this occurred during a
batch run or a logger thread wakeup, the entry could be filtered out
and never output to the reader.
Found one case where logcat.tail_time* tests failed which was fixed
with this adjustment.
Test: gTest logd-unit-tests, liblog-unit-tests and logcat-unit-tests
Bug: 38046067
Bug: 37791296
Change-Id: Icbde6b33dca7ab98348c3a872793aeef3997d460
While a reader is present, consider it a success, and not busy, if a
buffer is pruned down to pruneMargin plus one second of additional
margin of logspan. If not busy, no need to trigger any mitigations
regarding the readers, or to report any errors.
Side Effects are we no longer mitigate the reader when performing
chatty filtration. This is a positive side effect because we were
getting --wrap wakeups that seemed premature.
Add kickMe() and isBusy() methods to ease maintenance and uniformity
of actions.
Test: gTest liblog-unit-tests, logd-unit-tests & logcat-unit-tests
Test: manual: 'logcat -b all -c' repeat in a loop, at various logging
load levels, simultaneously 'logcat -b' all in another session.
Bug: 38046067
Change-Id: I3d0c8a2d416a25c45504eda3bfe70b6f6e09ab27
- android::pidToUid() additional checking. Make sure if we have to
convert a PID to an UID that the parse of /proc/<pid>/status
requires a trailing space after the number
- android::tidToPid() added, in the same vein as android::pidToUid().
- stats.tidToPid() added
- If no credentials, set PID to 0 and UID to DEFAULT_OVERFLOWUID
- If credentialed PID is 0, use stats.tidToPid()
- If credentialed UID is DEFAULT_OVERFLOWUID, use stats.pidToUid()
Test: remove +passcred from logd.rc for daemon and confirm very few
UID=65534 or PID=0 cases actually show up
Bug: 37985222
Change-Id: I7d20506e70e67beb3043d1537cf9450ab58dc278
logd.sepolicy_rate_limiter_* tests can fail individually so join them
together into one test. The new test logd.sepolicy_rate_limiter
fails as a group if the background sepolicy activity is too high, so
check it and report a warning that the test can fail as a result so it
can be forgiven during unit testing. The failure remains as a VTS
performance threshold that requires investigation.
The test takes a total of 45 seconds to run, it was split up as this
approaches the 60 second test timeout on go/apct.
Test: gTest logd-unit-tests --gtest_filter=logd.sepolicy_rate_limiter
(run in loop ensuring passes do not interfere with eachother)
Bug: 37791296
Change-Id: Ia865241f684c6b0de428702cbd5110dc17927c66
Tell init to set SO_PASSCRED on the socket before bind() and handoff.
Test: gtest logd-unit-test --gtest_filter=logd.statistics right after boot
Bug: 37985222
Change-Id: I318969ee3241834e5326233aabd97e52ef505969
Refine DAC security surrounding logd.daemon worker thread and add a
positive test for logd failure to access /data/system/packages.list.
- Add AID_PACKAGE_INFO to groups of worker thread.
- Move AID_SYSTEM to groups, setgid to AID_LOGD.
- Do not drop capabilities until after setting the uid and gids.
- Add a test that is part of logd.statistics test to check when
packagelistparser appears broken.
- If /data/system/packages.list is encrypted, ensure we do not pick
up the existing inode to ensure strong positive when finding access
problems.
- Replace all occurrences of NULL with nullptr in gTest code for
compliance with best practices.
Test: gTest logd-unit-tests --gtest_filter=logd.statistics
(expect consistent failure, later CLs fix)
Bug: 37751120
Bug: 36645158
Change-Id: I01b26fe5e25203246ae432d272c8daa9c07cab54
Separates logd body into a static library liblogd and
virtualize LogBuffer::log to be in a new interface class
LogBufferInterface. User could have different implementation.
Bug: 37756450
Test: liblog-unit-tests, logd-unit-tests and logcat-unit-tests
with (b/37791296).
Change-Id: I1504ff0e992744001b5a2e9abd45692d1318a152
Utilize logd-unit-tests as a CTS test
Goal is to check if the kernel logger is enabled.
Test: run cts tests
Bug: 31772697
Change-Id: I6d80350f3e40aff095f81b6600c40dd7d376bd74
Switch to a reader writer lock for the Element List lock. Also setup
for a reader writer lock for the Times list, but continue to use a
mutex where rdlock() and wrlock() are the same implementation for now.
This should improve general reader performance and prevent blocking of
other reader operations or exit by a single hung logd.reader.per
thread. For example, a full length logcat of an empty buffer (eg:
crash log buffer) will hold a lock while the iterator scans the entire
list.
Test: gTest liblog-unit-tests, logd-unit-tests, logcat-unit-tests
Bug: 37378309
Bug: 37483775
Change-Id: If5723ff4a978e17d828a75321e8f0ba91d4a09e0
Logspan down to the millisecond. Show a percentage if trimmed by
Chatty messages, a subspan from the newest to the newest chatty in
the log buffer. Sniff stats.add(elem), stats.subtract(elem) and
stats.dropped(elem) to generate the logspan data.
Test: gTest liblog-unit-tests, logd-unit-tests and logcat-unit-tests
Test: manual check Logspan statistics for being in range, added
temporary internal instrumentation to confirm expectations.
Bug: 37254265
Change-Id: I09c0d9375d5580315543c747b37976f9eeb9e408
Replace stats.add(elem) + stats.subtract(elem) with a new more
efficient method stats.addTotal(elem).
Test: gTest liblog-unit-test, logd-unit-tests and logcat-unit-tests
Bug: 37254265
Change-Id: I2b3c2ac44209772b38f383ae46fe6c4422b542cf
Helpful instrumentation to determine who is waiting for logger data.
Test: manual
Bug: 37274132
Bug: 37378309
Change-Id: I14fb1d9d15ae413930121048b770852359f06682
Add checking for impossible(tm) scenarios within LogBuffer::flushTo:
1) When iterating through the log entries, check if the iterator
returns two identical element references and break out of the loop.
2) Cap the maximum number of log entries we will skip while holding
the iterator lock at 4194304, break out of the loop.
We print a message to the kernel logs if we hit these cases.
ToDo: Remove this paranoia at some future date.
Test: gTest liblog-unit-tests logcat-unit-tests and logd-unit-tests
Bug: 37378309
Change-Id: I789594649db14093238828b9f6d1daeca8b780c2
Deal with a regression introduced in commit
5a34d6ea43 (logd: drop mSequence from
LogBufferElement) where log_time was compared against nsec() time
miscalculating the watermark boundary. When dealing with logcat
-t/-T, or any tail reading, add a margin to prune to back off by a
period of 3 seconds (pruneMargin).
Test: gTest liblog-unit-tests logcat-unit-tests and logd-unit-tests
Bug: 37378309
Change-Id: I72ea858e4e7b5fa91741ea84c40d2e7c3c4aa031
- moved __android_log_is_debuggable to a new public header
(log_properties.h)
- vendor version of sched_policy uses ALOG* instead SLOG*
Test: (sanity) liblog-unit-tests
Test: (sanity) libcutils_test (noting b/b/32972117, two tests continue
to fail)
Test: system/core as a whole makes with BOARD_VNDK_VERSION := current
now with no problems.
Test: boots/works on internal marlin
Bug: 33241851
(cherry picked from commit 1f83aa424f)
Merged-In: I5bc1f348dc0f0c8814bec5b5c3d2c52c825ab640
Change-Id: I5bc1f348dc0f0c8814bec5b5c3d2c52c825ab640
- moved __android_log_is_debuggable to a new public header
(log_properties.h)
- vendor version of sched_policy uses ALOG* instead SLOG*
Test: (sanity) liblog-unit-tests
Test: (sanity) libcutils_test (noting b/b/32972117, two tests continue
to fail)
Test: system/core as a whole makes with BOARD_VNDK_VERSION := current
now with no problems.
Test: boots/works on internal marlin
Bug: 33241851
Change-Id: I5bc1f348dc0f0c8814bec5b5c3d2c52c825ab640
* changes:
liblog: allow event tags to include some punctuations
liblog: logprint supports number of seconds time event field
logcat: test: standardize rest() to let logs land when injecting
Add s to report time in seconds. The time could be a period, duration
or monotonic, expanded to seconds, minutes, hours and days. gTest has
to acquire a dynamic tag allocation as there are no users of this
feature yet.
Looking to the future, audio media logging has binary content similar
to the binary events structures Android logging uses and they have
a definition of a duration field in their internal binary logging, so
may be of use when we unify the logs.
Test: gTest logcat-unit-tests --gtest_filter=*.descriptive
Bug: 31456426
Change-Id: I262c03775983b3bc7b1b00227ce2bb2b0f357bec
Prefix long truncated names with an ellipse (...). Shift left as
much as possible when doing so, but keep spaces between command
name and other tabular fields.
Test: manual/visual
Bug: 37254265
Change-Id: I185b1e121ba911a9410a8b6624e013d5a531962b
(cherry picked from commit c27f12a3d396f113c5ae09d2f2c8ff7de3f8b551)
logd assumes that it is running in UTC time zone.
However, if persist.sys.timezone is set at some point later,
that affects and confuses logd behavior.
To avoid such a case, this CL sets TZ to UTC, which overrides
the property's behavior.
Test: Ran CtsOsTestCases.
Test: gTest liblog-unit-tests, logd-unit-tests and logcat-unit-tests
Bug: 33566779
Change-Id: Ib9edd4cb06f019a33aaf8d77d33bd82fdbbda480
If setcon fails, try alternate setcon, and then if it still
fails call getcon to confirm if it is an OK sepolicy context
anyways.
Test: gTest logd-unit-tests --gtest_filter=logd.sepolicy*
Change-Id: Iaf20b8a1a4a7312247288e1879884a54893c15ae
Reduce the period we are willing to look back at for out-of-order
entries. Cap the number of iterations we are willing to look back
for out-of-order entries to 300.
Test: gTest liblog-unit-tests, logd-unit-tests and logcat-unit-tests
Bug: 36875387
Bug: 36874561
Bug: 36861142
Change-Id: Icee289dfc0a37ccab9912dc8ab40a10ef3967b7a
