Previously, chatty had logic that would skip a certain number of log
entries to satify pruning, but otherwise keep the reader connected.
This was a best-effort attempt at helping pruning and had additional
logic that handled further disruptions, if logd's memory was 2x the
allotted memory.
The new logic has two components:
1) memcpy() each individual log message in FlushTo() such that there
are no references to the underlying log data without a lock held.
Note, that this memcpy is completely negligible for performance.
2) In Prune(), immediately delete all log chunks required to reduce
memory to the allotted amount, which is now safe given 1). If readers
will lose logs, continue to print a warning.
This additionally makes the Clear() logic deterministic. It was
previously best effort in chatty, but will immediately and always
clear all logs for SerializedLogBuffer.
Bug: 163617910
Test: logging unit tests
Test: Prune() immediately frees buffers during high log pressure
Test: Clear() immediately frees buffers during high log pressure
Change-Id: I40fe9b791312af3dc256b166e5c34425f4ca51ac
See the comment in the code for more details. 'wrapped' readers are
uncommon and error prone, and this change makes them more reliable.
Its side effect is that wrapped readers will wake more often, but
they'll still be batched to a large degree.
Bug: 163617910
Test: logging unit tests
Test: logcat --wrap does the right thing
Change-Id: I4b6f8331ff7854787c97f821b2a5bf8d7da321c6
liblog exposed __android_logger_get_buffer_size() which queries log
size properties, but that should not be a generic library function.
Logd should be the only process that queries these properties and
other processes should query the actual used log sizes from logd via
the android_logger_get_log_*_size() functions.
Also, always use 1MB for log buffer tests, instead of just on host and
various other clean up related to improper types.
Test: log buffers are correctly sized
Merged-In: I9b7c86bf58e569618737afe9097cf1c4d4e61d95
Change-Id: I9b7c86bf58e569618737afe9097cf1c4d4e61d95
When calculating the space used for pruning, if a log chunk is
compressed, that size is used otherwise the uncompressed size is
used. This is intended to reach a steady state where 1/4 of the log
buffer is the uncompressed log chunk that is being written to and the
other 3/4 of the log buffer is compressed logs.
If we wait until there are no readers referencing the log chunk before
compressing it, we end up with 2 uncompressed logs (the one that was
just filled, that readers are still referencing, and the new one that
was allocated to fit the most recent log), which take up 1/2 of the
log buffer's allotted size and will thus cause prune to delete more
compressed logs than it should.
Instead, we should always compress the log chunks in FinishWriting()
such that the compressed size will always be used for log chunks other
than the one that is not actively written to.
Decompressed logs due to readers are ephemeral by their nature and
thus don't add to the log buffer size for pruning.
Test: observe that log buffers can be filled in the presence of a reader.
Change-Id: Ie21ccff032e41c4a0e51710cc435c5ab316563cb
This was a premature optimization. Profiling shows that decompressing
and deleting these logs is rather fast and overall CPU utilization is
lower without the added thread.
Test: profile logd with/without this thread
Change-Id: I31bd52077b495d562dd5797585191dc200ad3859
ChattyLogBuffer ignores the metadata (timestamp, pid, std::list<>
iterators, etc) of log entries when calculating the size used by a
given log buffer. For example, if 1MB is the specified size of the
'main' log buffer, logd will use between ~1.3MB and ~2MB of overall
memory for 'main' log buffer. LogStatistics does track the overall
memory used and labels it 'Overhead', however this 'Overhead' is only
informative and is not used for Pruning or Chatty calculations.
This is problematic, since it makes logd's memory usage inconsistent:
depending on the pattern of logging, there can be substantially more
memory used than the specified log buffer size. This is further
complicated by the fact that chatty messages are entirely metadata and
therefore not counted as contributing to the log buffer size.
This change would switch logd to always track the full size of log
buffers, but there are two problems with this approach:
1) Unless users double their buffer sizes, then they'd have
substantially fewer logs after the change
2) Chatty logic would change and it's difficult to evaluate.
Therefore this change only provides the framework to track the full
size of log buffers. This allows an apples to apples comparison of
ChattyLogBuffer and SerializedLogBuffer. With this option enabled,
logd reports the following values:
ChattyLogBuffer:
Total log size (logcat -g), 'Total' / 'Now' (logcat -S), and
'Overhead' (logcat -S) all report the full size of log entries
including metadata.
SerializedLogBuffer:
Total log size (logcat -g) and 'Overhead' (logcat -S) report the
compressed size of the log entries including metadata.
'Total' / 'Now' (logcat -S) reports the uncompressed size of the log
entries that are available including metadata.
Test: logging statistics are correct
Change-Id: If17682af8bb605f31387d7b210b69a301dd48f07
SerializedFlushToState::PopNextUnreadLog() was calling
AddMinHeapEntry() to replenish the element that was just popped off of
the heap, however AddMinHeapEntry() also manages reference counts for
the buffers, and this resulting in the following scenario:
PopNextUnreadLog() returns a pointer referencing log buffer #1
AddMinHeapEntry() sees that all logs from buffer #1 has been read, so
it decrements the reference count
The caller of PopNextUnreadLog() uses the result which references
invalid memory.
This calls CheckForNewLogs() within HasUnreadLogs() instead of
requiring a separate call, which fixes an additional issue where
continuing from the loop in SerializedLogBuffer::FlushTo() may not
pick up subsequent logs in a given log buffer, since CheckForNewLogs()
wouldn't be called. This was exacerbated by the above change.
This adds a test to check the reference counts for this case and fixes
an argument mismatch in SerializedFlushToStateTest.
This adds the corpus that surfaced the issue.
Bug: 159753229
Bug: 159783005
Test: these unit tests, run fuzzer without error
Change-Id: Ib2636dfc14293b7e2cd00876b9def6e9dbbff4ce
Logd never deletes SerializedLogBuffer, so it seemed reasonable to
detach the deleter thread, however unit tests and fuzzers do delete
SerializedLogBuffer, so we must safely join the deleter thread in the
destructor.
This simplifies the deleter thread code and ensures that only one
deleter thread will be running at a time.
Test: fuzzing works
Change-Id: I69c7447109898a1bb7038a03337cadacb1213281
In order of severity:
1) Add a CHECK() that a pointer is not nullptr, where the analyzer
believes this is possible.
2) Add `final` appropriately to functions called from constructors.
3) Add missing cloexec flags.
4) Add missing `noexcept` and other subtle performance warnings
Test: build with clang-tidy
Change-Id: Ifd9a1299a51027a47382926b2224748b5750d6cf
Initial commit for a SerializedLogBuffer. The intention here is for
the serialized data to be compressed (currently using zlib) to allow
for substantially longer logs in the same memory footprint.
Test: unit tests
Change-Id: I2528e4e1ff1cf3bc91130173a107f371f04d911a
Tom Cherry