Commit graph

18 commits

Author SHA1 Message Date
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
aeaaf81c2c liblog: logd: logcat: Split out log/logger.h into public and private.
log/logger.h pieces moved into log/log.h.  Correct for some
minor Android Coding standards.

Test: gTests liblog-unit-tests, logd-unit-tests and logcat-unit-tests
Bug: 19235719
Bug: 26552300
Bug: 31289077
Bug: 31456426
Change-Id: I0a19fd8788eec20a582e72e4c62c04534bdb1b9a
2016-10-24 11:12:49 -07:00
Mark Salyzyn
0dd4431072 logd: logcat: Replace log/log.h with android/log.h
Should use android/log.h instead of log/log.h as a good example
to all others.

Test: Compile
Bug: 26552300
Bug: 31289077
Change-Id: If4c9711eb57267d4707b03d54a932af9de241b13
2016-09-30 12:47:05 -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
317bfb923c logd: Allow (some) headers to be individually importable
(cherry pick from commit 2ad0bd0a9b)

LogReader.h needs to be individually importable.

Fix a few others, drop includes of local includes, let them be
included in source instead and allow headers to be included
alphabetically. Was not a complete audit since goal was to
separate LogReader.h out from the pack.

Bug: 27242723
Change-Id: Ic7759ef90995e5bd285810706af33550c73cf5b5
2016-02-25 12:42:31 -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
98dca2d0b1 logd: logtimes switch to std::list
Bug: 23350706
Change-Id: Icc60dd06119ea20a22610644ff880d5135363aba
2015-08-20 08:36:03 -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
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
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