Commit graph

23 commits

Author SHA1 Message Date
Jintao_Zhu
5f93072db3 logd: fix memory leak due to slow reader
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
2018-11-12 10:24:15 -08:00
Tom Cherry
4f22786cc9 logd: rework logic for LogTimeEntry
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
2018-10-12 18:28:59 -07:00
Yi Kong
760a35a91c Remove execute bit for source files
Test: ls -l
Change-Id: Id09514a03f82c89e6350a5f9e34b9ef8bfe27b7e
2018-07-13 17:45:39 -07:00
Hao Wang
f6e2296953 logd: enhance multiple blocking readers performance
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
2017-12-05 18:46:24 +08:00
Mark Salyzyn
3c501b50b4 logd: reader/writer element locks
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
2017-04-20 08:24:38 -07:00
Mark Salyzyn
ae2abf112c logd: correctly label identical lines
Move lastTid array from local in LogBuffer::flushTo to per-reader
context in LogTimes::mLastTid and pass into LogBuffer::flushTo.

Replace NULL with nullptr in touched files.

Simplify LogTimeEntry::cleanSkip_Locked initialization of skipAhead
to memset, to match mLastTid memset initialization.

Test: gTest liblog-unit-tests, logd-unit-tests & logcat-unit-tests
Test: adb logcat -b all | grep chatty | grep -v identical
Bug: 36488201
Change-Id: I0c3887f220a57f80c0490be4b182657b9563aa3f
2017-03-31 13:56:38 -07:00
Mark Salyzyn
5a34d6ea43 logd: drop mSequence from LogBufferElement
Use getRealTime() instead and leverage private liblog log_time
comparison and math functions.  This saves 8 bytes off each
element in the logging database.

Test: gTest liblog-unit-tests logd-unit-tests logcat-unit-tests
Bug: 35373582
Change-Id: Ia55ef8b95cbb2a841ccb1dae9a24f314735b076a
2017-03-16 08:22:00 -07:00
Mark Salyzyn
501c373916 logd: specify clang format
Switch _all_ file's coding style to match to ease all future changes.

SideEffects: None
Test: compile
Bug: 35373582
Change-Id: I470cb17f64fa48f14aafc02f574e296bffe3a3f3
2017-03-13 10:31:09 -07:00
Mark Salyzyn
c348416198 logd: clarify release_Locked() for static analyzer
(cherry pick from commit 0ecdec7a09)

release_Locked() is called with a reference count and threadRunning,
the static analyzer can not tell this and estimates that a call to
delete this will occur. So let us invent a new call
release_nodelete_Locked() to ensure it is clear we will not be
arranging a delete this in the context of this code path. The
delete this will follow in the immediate codepath in this function
after threadRunning is cleared, and decRef_Locked() is called.

Change will also remove any developer FUD regarding release_Locked()
usage at this location.

SideEffects: None

Bug: 27434831
Change-Id: I91b060b2dadc72cc449fa381c934afb577bee037
2016-03-02 11:37:21 -08:00
Mark Salyzyn
8fa8896d2e logd: security buffer only AID_SYSTEM reader
- limit AID_SYSTEM uid or gid to read security buffer messages
- adjust liblog tests to reflect the reality of this adjustment

To fully test all security buffer paths and modes

$ su 0,0,0 /data/nativetest/liblog-unit-tests/liblog-unit-tests --gtest_filter=liblog.__security*
$ su 1000,1000,1000 /data/nativetest/liblog-unit-tests/liblog-unit-tests --gtest_filter=liblog.__security*
$ su 2000,2000,2000 /data/nativetest/liblog-unit-tests/liblog-unit-tests --gtest_filter=liblog.__security*

ToDo: Integrate the above individually into the gTest Q/A testing

Bug: 26029733
Change-Id: Idcf5492db78fa6934ef6fb43f3ef861052675651
2016-02-01 13:29:06 -08:00
Mark Salyzyn
b75cce0389 logd: wakeup on wrap or timeout
If a timeout is specified for the reader, then go to sleep
with the socket open. If the start time is about to get
pruned in the specified log buffers, then wakeup and dump
the logs; or wakeup on timeout, whichever comes first.

Bug: 25929746
Change-Id: I7d2421c2c5083b33747b84f74d9a560d3ba645df
2015-12-07 14:24:02 -08:00
Mark Salyzyn
de4bb9c1a7 logd: update region lock after entry has passed to reader socket
- The reader region level indicates the location to protect, but once
  it has been passed to the calling reader, then allow us to go
  one beyond so that a clear or prune thread can remove the entry.

Bug: 23711431
Change-Id: I0f2389858dd8c83366c034360f67d7c363625b56
2015-10-07 16:23:57 -07:00
Mark Salyzyn
047cc0729f logd: filters remove leading expire messages and rate
- Cleanup resulting from experience and feedback
- When filtering inside logd, drop any leading expire messages, they
  are cluttering up leading edge of tombstones (which filter by pid)
- Increase and introduce EXPIRE_RATELIMIT from 1 to 10 seconds
- Increase EXPIRE_THRESHOLD from 4 to 10 count
- Improve the expire messages from:
   logd : uid=1000(system) too chatty comm=com.google.android.phone,
                                                   expire 2800 lines
  change tag to be more descriptive, and reduce accusatory tone to:
   chatty : uid=1000(system) com.google.android.phone expire 2800
                                                               lines
- if the UID name forms a prefix for comm name, then drop UID name

Change-Id: Ied7cc04c0ab3ae02167649a0b97378e44ef7b588
2015-06-05 08:05:05 -07:00
Mark Salyzyn
7718778793 logd: Cleanup
- Android Coding Standard for Constructors
- Side effects NONE

Change-Id: I2cda9dd73f3ac3ab58f394015cb810820093d47b
2015-05-12 15:51:46 -07:00
Mark Salyzyn
f7c0f75275 logd: replace internal CLOCK_MONOTONIC use with sequence numbers
- switch to simpler and faster internal sequence number, drops
  a syscall overhead on 32-bit platforms.
- add ability to break-out of flushTo loop with filter return -1
  allowing in reduction in reader overhead.

Change-Id: Ic5cb2b9afa4d9470153971fc9197b07279e2b79d
2015-03-18 12:43:23 -07:00
TraianX Schiau
da6495d06f logd: Fix pruning
In a scenario in which an on-line (blocking) client is running and
a clean is attempted (logcat -c), the following can be observed:

1) the on-line logger seems to freeze
2) any other clear attempt will have no effect

What is actually happening:

In this case prune function will "instruct" the oldest timeEntry
to skip a huge number (very close to ULONG_MAX) of messages, this
being the cause of 1.

Since the consumer thread will skip all the log entries, mStart
updating will also be skipped. So a new cleaning attempt will have
the same oldest entry, nothing will be done.

Fix description:
a. keep a separated skipAhead count for individual log buffers (log_id_t)
      LogTimeEntry::LogTimeEntry
      LogTimeEntry::FilterSecondPass
      LogTimeEntry::skipAhead
      LogTimeEntry::riggerSkip_Locked

b. update LogTimeEntry::mStart even if the current message is skipped
      LogTimeEntry::FilterSecondPass

c. while pruning, only take into account the LogTimeEntrys that are monitoring
   the log_id in question, and provide a public method of checking this.
      LogTimeEntry::isWatching
      LogTimeEntry::FilterFirstPass
      LogTimeEntry::FilterSecondPass

d. Reset the skip cont befor the client thtread starts to sleep, at this point
   we should be up to date.
      LogTimeEntry::cleanSkip_Locked
      LogTimeEntry::threadStart

Change-Id: I1b369dc5b02476e633e52578266a644e37e188a5
Signed-off-by: TraianX Schiau <traianx.schiau@intel.com>
2015-01-14 19:12:47 +00:00
Mark Salyzyn
a16f761faa logd: persistent reader threads
(cherry picked from commit c113c5813e)

Bug: 16822776
Change-Id: I5bea468a41089b51108880044f32e2b2df1278e7
2014-08-12 18:59:35 +00:00
Mark Salyzyn
8d7656b8c1 logd: logcat unexpected EOF on slow consoles
Change-Id: I3520aa05e080de85df352ef36ae16e0406311f3c
2014-06-06 15:08:37 +00:00
Mark Salyzyn
8daa9af02d logd: add thread setname
- permits easier determination of logd thread at
  fault in a stack trace from debuggerd.

Bug: 14275676
Change-Id: Iac2c523147e2bcce34ab7ddcecd02582c5fa7cc0
2014-04-29 00:37:37 +00:00
Mark Salyzyn
765f782891 logd: transitory reader thread create should be detached
Bug: 13692914
Change-Id: Ia7306e6e844ae9f17c6f594bf6b25f3148652570
2014-04-04 13:12:56 -07:00
Mark Salyzyn
fa3716b250 logd: liblog: logcat: Arbitrary time to tail
Change-Id: I10e8d92c933e31ee11e78d2d1114261a30c4be0e
2014-03-14 10:23:51 -07:00
Mark Salyzyn
c03e72cc1c logd: Adjust to match defacto coding style
(cherry picked from commit c46f77bd2a)

Change-Id: I80685cdc7116e10c5a5a77abe856fd96804f9117
2014-02-26 09:54:23 -08:00
Mark Salyzyn
0175b0747a logd: initial checkin.
* Create a new userspace log daemon for handling logging messages.

Original-Change-Id: I75267df16359684490121e6c31cca48614d79856
Signed-off-by: Nick Kralevich <nnk@google.com>

* Merge conflicts
* rename new syslog daemon to logd to prevent confusion with bionic syslog
* replace racy getGroups call with KISS call to client->getGid()
* Timestamps are filed at logging source
* insert entries into list in timestamp order
* Added LogTimeEntry tail filtration handling
* Added region locking around LogWriter list
* separate threads for each writer
* /dev/socket/logd* permissions

Signed-off-by: Mark Salyzyn <salyzyn@google.com>

(cherry picked from commit 3e76e0a497)

Author: Nick Kralevich <nnk@google.com>
Change-Id: Ice88b1412d8f9daa7f9119b2b5aaf684a5e28098
2014-02-26 09:52:35 -08:00