Kernel panic - not syncing: Out of memory occurred once after 8 hours
automatic test which cases are about Summary:logd memory leak UTResult
: 1/1
IssueID: 93440
Rootcause: the method "LogTimeEntry::FilterSecondPass"(called inside
"LogBuffer::flushTo") does not check the condition flag
"LogTimeEntry::mRelease" which will be set to true when "logd" begins
to kick off a client when it finding the client is slow-est.
Therefore the client cannot be kicked off and hence the log-element
list becomes longer and longer if the slowest client reading more
slower than the writer writing.
Change-Id: I91a44a393e63b3122c15ce269ee195e0eb4339e8
Solution: add the check.
Test: logd kills slow reader
This code was accidentally deleted in the refactoring of
4f22786cc9 cause the
logd.timeout_no_start test to start failing.
Bug: 117942520
Test: logd unit tests
Change-Id: Id7994230a89d7f8c2cb1f36a8ca1175a6b398de0
LogTimeEntry's lifecycle is spread out in various locations. It
further seems incomplete as there is logic that assumes that its
associated thread can exit while the underlying LogTimeEntry remains
valid, however it doesn't appear that that is actually a supported
situation.
This change simplifies this logic to have only one valid state for a
LogTimeEntry: it must have its thread running and be present in
LastLogTimes. A LogTimeEntry will never be placed into LastLogTimes
unless its thread is running and its thread will remove its associated
LogTimeEntry from LastLogTimes before it has exited.
This admittedly breaks situations where a blocking socket gets issued
multiple commands with different pid filters, tail lines, etc,
however, I'm reasonably sure that these situations were already
broken. A check is added to close the socket in this case.
Test: multiple logcat instances work, logd.reader.per's are cleaned up
Change-Id: Ibe8651e7d530c5e9a8d6ce3150cd247982887cbe
Add FALLTHROUGH_INTENDED for clang compiler.
Bug: 112564944
Test: build with global -Wimplicit-fallthrough.
Change-Id: I40f8bbf94e207c9dd90921e9b762ba51abab5777
This change removes the call to prctl(PR_SET_KEEPCAPS, 1), because now
that logd is being run with ambient capabilities, init will set the
KEEP_CAPS / KEEP_CAPS_LOCKED securebits.
Bug: 110127913
Test: liblog-unit-tests, logd-unit-tests, logcat-unit-tests
(on an aosp_sailfish-userdebug)
Change-Id: I72b6a49c5cd1552085f9ad44cb19a7333a13eeea
This change moves logd's capabilities from being file based to being set
by init through ambient capabilities.
Bug: 62845925
Test: sailfish:/ # grep Cap /proc/`pidof logd`/status
CapInh: 0000000000000000
CapPrm: 0000000440000000
CapEff: 0000000440000000
CapBnd: 0000000440000040
CapAmb: 0000000000000000
$ capsh --decode=0x440000040
0x440000040=cap_setgid,cap_audit_control,cap_syslog
Test: liblog-unit-tests, logd-unit-tests, logcat-unit-tests
Change-Id: I28c7c4ad37ad5eafd399aef78c303ce31298a9ef
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
(cherry picked from commit 3a5acdaa8d)
LogBuffer::log() returns either a negative number on error or a
positive number indicating the length of the message written.
Therefore, the check to notify kernel log readers of a new message
should be that this function's return value is > 0.
Bug: 78209416
Test: `adb logcat -b kernel` updates when new log messages are present
Change-Id: Icc18c0c22e62340994e5c26aedb72282d61c1541
Events in the LogBuffer are supposed to be sorted by timestamp, but for a variety
of reasons that doesn't always happen. When a LogReader is reading from LogBuffer,
LogBuffer starts at the newest event, and scans backward through the list, looking
for the last event. Previously it would accept a couple that were a little bit out
of order, but if it found one that was ancient, it would just bail. This change
removes that check for the ancient messages. They are probably indicative of
something else upstream, but since there is no invariant of the list being sorted,
this change simplifies the search algorithm, and makes it look only at the previous
300 events.
Bug: 77222120
Test: while true ; do frameworks/base/cmds/statsd/run_tests.sh 2h ; done
Change-Id: I0824ee7590d34056ce27233a87cd7802c28f50e4
(cherry pick from commit 22712428b8)
Discovered while running AddressSanitizer, binary events were fed
into logd that were smaller than the binary event string header.
Fix is to check the buffer sizes before performing the memcmp
operation.
Test: compile
Bug: 74574189
Change-Id: Ic01ef6fb0725258d9f39bbdca582ed648a1adc5d
While running AddressSanitizer, binary events were fed into logd
that were smaller than the binary event string header. Fix is to
check the buffer sizes before performing the memcmp operation.
Test: compile
Bug: 74574189
Change-Id: Ic01ef6fb0725258d9f39bbdca582ed648a1adc5d
Select a low rate-limit to cut down on logspam and resulting
performance regressions.
Functionally reverts 247d682fe1
(logd: sepolicy dynamic rate limiting) and sets a static low
rate-limit. Before 247d682f, the limit was statically set to 20.
247d682f continued to support 20, but if sustained dropped the limit
to 5. This revert leaves us at 5 so as not to impact performance.
Test: /data/nativetest/logd-unit-tests/logd-unit-tests \
--gtest_filter=logd.sepolicy_rate_limiter
[ PASSED ] 1 test.
Bug: 71538411
Change-Id: I6c92f4ba825cc24beb8f1f1b79258fa8097c837b
Prevent a possible DOS of the kernel logs because the runtime result
could differ from the boottime result.
Test: adb bugreport, then examine kernel log
Change-Id: I140fd465f2e691c751d92af50dbdf95e23c121d8
This reverts commit ec0c886da6.
I will submit the new permission check through AOSP. Revert this CL to avoid merge conflict.
Change-Id: I5d29ad2cda3579b37dd7136037af0c85c3917f6b
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
Jintao_Zhu