Commit graph

139 commits

Author SHA1 Message Date
Mark Salyzyn
618d0dec50 logd: refine is_prio
- Heuristics associated with translation of kernel messages to
  Android user space logs.
- Limit is_prio to 4 characters, we got false positives on hex
  values like <register contents> with no alpha chars.
- x11 and other register definitions are not valid tags, en0 is
- fix some Android coding standard issues

Change-Id: Idc3dcc53a2cb75ac38628c8ef7a5d5b53f12587a
2015-07-22 07:36:03 -07:00
Mark Salyzyn
ed777e9eec logd: serialize accesses to stats helpers
Quick low-risk to resolve possible hash table corruption.
Resolved an unlikely path memory leak.

ToDo: replace lock with nested lock so no lock
      helpers are required.

Bug: 22068332
Change-Id: I303ab06608502c7d61d42f111a9c43366f184d0c
2015-06-25 07:39:24 -07:00
Mark Salyzyn
ee49c6a670 logd: missing klogd content
- regression in log_strtok_r (part deux) In commit
      'logd: fix kernel logline stutter'
  2c3b300fd8 we introduced log_strtok_r.
  as a replacement for strtok_r that dealt with a problem with
  some kernel log messages. Fix is to refine definition of
  is_timestamp to not match on patterns like [0], requiring
  a single period. Another fix is to refine definition of
  is_prio to properly escape non-digit content.
- Missing content because SYSLOG_ACTION_SIZE_BUFFER with added logging
  is too short for full read of SYSLOG_ACTION_READ_ALL dropping
  initial content. Add a margin for additional 1024 bytes.
- Absolute _first_ log entry has sequence number of 1, which is
  specifically dropped, start sequence count at 1 rather than 0.
- Remove trailing space for efficiency.
- If tag exists but no content, trick into kernel logging.

Bug: 21851884
Change-Id: I0867a555a3bca09bbf18d18e75e41dffffe57a23
2015-06-15 21:19:10 +00:00
Mark Salyzyn
e59c469fa8 logd: filter on __android_log_is_loggable
- Default level when not specified is ANDROID_LOG_VERBOSE
  which is inert.

Bug: 20416721
Bug: 19544788
Bug: 17760225
Change-Id: Icc098e53dc47ceaaeb24ec42eb6f61d6430ec2f6
2015-06-12 10:35:09 -07:00
Riley Andrews
aede9897df Lower the priority of the threads in logd/logcat.
(cherry pick from commit d98f4e8af5)

sched_batch implies only a penalty to latency in scheduling, but
does not imply that the process will be given less cpu time. Increase
the nice level to 10 to prioritize it below ui threads.

Bug: 21696721
Change-Id: I075af059dc755402f7df9b0d7a66cca921ff04b2
2015-06-09 12:40:20 -07:00
Mark Salyzyn
3e21de2915 logd: build breakage
OPEN_BRACKET_SPACE comparison always false

Change-Id: I1ff4288b4b79a49702727d3a8b8c8f179f500951
2015-06-08 14:52:14 -07:00
Mark Salyzyn
2c3b300fd8 logd: fix kernel logline stutter
- look for cases where one log line contains two without a newline.
- rare condition, occurs when a printk does not have
  a terminating newline under certain race conditions.
- the newline may be performed broken up as a second call
- the timestamps can be reversed (showing the race effects).
- driver(s) should really have the newline in there log messages.

Change-Id: Ibfb56b32047da3d6513db059ca6edad0f0105168
2015-06-08 13:10:31 -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
511338dd57 logd: switch to unordered_map from BasicHashtable
BasicHashtable is relatively untested, move over to
a C++ template library that has more bake time.

Bug: 20419786
Bug: 21590652
Bug: 20500228
Change-Id: I926aaecdc8345eca75c08fdd561b0473504c5d95
2015-06-03 13:03:07 -07:00
Mark Salyzyn
100658c303 init.rc: logd: Add logpersistd (nee logcatd)
- logpersistd is defined as a thread or process in the context of the
  logd domain. Here we define logpersistd as logcat -f in logd domain
  and call it logcatd to represent its service mechanics.
- Use logcatd to manage content in /data/misc/logd/ directory.
- Only turn on for persist.logd.logpersistd = logcatd.
- Add logpersist.start, logpersist.stop and logpersist.cat debug
  class executables, thus only in the eng and userdebug builds.

ToDo: Wish to add Developer Options menu to turn this feature on or
off, complicated by the fact that user builds have no tools with
access rights to /data/misc/logd.

Bug: 19608716
Change-Id: I57ad757f121c473d04f9fabe9d4820a0eca06f31
2015-06-02 15:17:59 -07:00
Mark Salyzyn
a8b6131ddf Merge "logd: test modernization" 2015-06-01 21:16:58 +00:00
Mark Salyzyn
10a124d342 Merge "logd: whitelist should not preserve expire messages" 2015-06-01 21:16:57 +00:00
Mark Salyzyn
5921276a16 logd: KISS & fix preserve a day
Code in 833a9b1e38 was borken,
simpler approach is to simply check last entry (to save a
syscall) minus EXPIRE_HOUR_THRESHOLD. This does make longer logs
less likely to call upon the spam detection than the algorithm
being replaced, but sadly we ended up with a log entry in the
future at the beginning of the logs confounding the previous
algorithm.

Bug: 21555259
Change-Id: I04fad67e95c8496521dbabb73b5f32c19d6a16c2
2015-06-01 13:06:35 -07:00
Mark Salyzyn
5392aac95d logd: deal with sloppy leading expire messages
The odds of chatty content also leading the logs is pretty high eg:

 1799 12017 I logd: uid=10007 chatty comm=Binder_B, expire 4 lines
 1799  1829 I logd: uid=10007 chatty comm=Binder_2, expire 4 lines
 1919 20637 I logd: uid=10007 chatty comm=m.sersistent, expire 1 line
 1919 20638 I logd: uid=10007 chatty comm=s.persistent, expire 1 line
 1919  2316 I logd: uid=10007 chatty comm=UlrDispatch, expire 4 lines
19379 20634 I logd: uid=10045 chatty, expire 14 lines
19379 19388 I logd: uid=10045 chatty comm=lizerDaemon, expire 4 lines
  591  4396 I logd: uid=1000 chatty comm=Thread-220, expire 5 lines
  591  1377 I logd: uid=1000 chatty comm=Thread-92, expire 4 lines
 1919  2267 I logd: uid=10007 chatty comm=WifiScanner, expire 4 lines
  591  4397 I logd: uid=1000 chatty comm=DhcpClient, expire 4 lines
  591  4398 I logd: uid=1000 chatty comm=Thread-222, expire 4 lines
  226   580 D CommandListener: Setting iface cfg

Change-Id: I5ab24bc7bf5d2690bae7e789831b07f23ff8bcc6
2015-06-01 13:04:09 -07:00
Mark Salyzyn
62d6a2a921 logd: test modernization
Bug: 19603976
Change-Id: Ie920c128e7e6a436fea7a96c7d68bc39e13a2ad4
2015-05-26 12:24:51 -07:00
Mark Salyzyn
c5bf3b8304 logd: whitelist should not preserve expire messages
Change-Id: I56275c73191b96aa21e7b4049d401e1f44211f9b
2015-05-21 13:01:56 -07:00
Mark Salyzyn
833a9b1e38 logd: worst-UID only to preserve a day
Do not invoke worst-UID pruning in the face of other
UIDs logs that are more than a day old, switch to
pruning oldest only.

Change-Id: Icf988b8d5458400a660d0f8e9d2df3f9d9a4c2d9
2015-05-20 09:47:54 -07:00
Mark Salyzyn
d1371a8b8b Merge "logd: Add TID statistics" 2015-05-13 16:17:37 +00: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
ae4d928d81 logd: Add klogd
- Add a klogd to collect the kernel logs and place them into a
  new kernel log buffer
- Parse priority, tag and message from the kernel log messages.
- Turn off pruning for worst UID for the kernel log buffer
- Sniff for 'PM: suspend exit', 'PM: suspend enter' and
  'Suspended for' messages and correct the internal definition
  time correction against monotonic dynamically.
- Discern if we have monotonic or real time (delineation 1980) in
  audit messages.
- perform appropriate math to correct the timestamp to be real time
- filter out any external sources of kernel logging

Change-Id: I8d4c7c5ac19f1f3218079ee3a05a50e2ca55f60d
2015-05-12 15:51:46 -07:00
Mark Salyzyn
17ed6797df logd: Add TID statistics
Bug: 19608965
Change-Id: Ifbf0b00c48ef12b5970b9f9f217bd1dd8f587f2c
2015-05-12 12:57:25 -07:00
Mark Salyzyn
344bff4391 logd: Add Tag statistics
- Optional class of statistics for events Tags
- export tagToName from LogBuffer (located in main.cp to address
  https://android-review.googlesource.com/#/c/110204)
- Can not handle dropped because getTag() can not work,
  will need to be fixed if we start filtering.

Bug: 19608965
Change-Id: I7b90607ca588bf37bab71f19b1570a290e772776
2015-05-12 12:53:27 -07:00
Mark Salyzyn
7297278ade Merge "logd: pidToName deficiency" 2015-05-12 19:38:40 +00:00
Mark Salyzyn
80b129f9f0 Merge "logd: uidToName add dex2oat UID" 2015-05-11 23:51:32 +00:00
Nick Kralevich
9667a66019 Revert "libaudit: limit to 5 selinux denials per sec"
The shamu instabilities continued even after throttling SELinux denials
to 5/second. 5 denials per second is too low when doing device bringup,
and there have been some complaints about lost SELinux denials. See,
for example, http://comments.gmane.org/gmane.comp.security.selinux/21941

Bring the limit back up to 20/second to prevent dropping too many
denials on the floor.

This reverts commit a15db51bbf.

Change-Id: I05e85cce0a792d05aa557fcc614c0fc019c15014
2015-05-09 12:41:41 -07:00
Mark Salyzyn
023f51f360 logd: uidToName add dex2oat UID
- When searching for uidToName from /data/system/packages.list
  one must search for the uid % AID_USER;
- If uid % AID_USER is greater than AID_SHARED_GID_START - AID_APP,
  then subract it and try again to pick up uidToName.

Change-Id: I24df42957ff7e746fffa5d39484637b1b726b9c0
2015-05-07 09:16:02 -07:00
Mark Salyzyn
aa43ae2268 logd: pidToName deficiency
any logging in zygote permanently sets the pidToName

Change-Id: I0b8fdc96fb5965a04d4dc4293c39815beef5eb8e
2015-05-05 12:34:16 -07:00
Mark Salyzyn
aaf9c1b3b4 Merge "logd: class hierarcy for Uid and Pid statistics." 2015-05-05 16:47:03 +00:00
Mark Salyzyn
21fb7e0b75 logd: improve details on chatty records
- Report applications UID, TID/PID by name.
- change wording to have an accurate connotation
- drop privilege check since filtered upstream

Bug: 19608965
Bug: 20334069
Bug: 20370119
Change-Id: I2b1c26580b4c2de293874214ff5ae745546f3cca
2015-04-30 13:14:51 -07:00
Mark Salyzyn
35173a9ac5 logd: reduce chance of dropped 1 messages
- do not time out at 1 second if drop has count of less than 4

Bug: 20334069
Bug: 20370119
Change-Id: I787cb553dfab5ed71abd6ed72b63de675f834e0c
2015-04-30 13:14:51 -07:00
Mark Salyzyn
653f9581bf Merge "logd: per UID less aggressive 12.5% threshold" 2015-04-23 14:41:48 +00:00
Mark Salyzyn
e06a6e0f26 logd: ratelimit drop messages to 1/sec
Bug: 20334069
Bug: 20370119
Change-Id: I6f850aec46c4df1c99a5b1f28db75d071e134ad5
2015-04-22 11:58:37 -07:00
Mark Salyzyn
d717d805d4 logd: per UID less aggressive 12.5% threshold
Per-UID quota has a threshold of 12.5% of the total log size.
If less than that space is taken by the UID, then we
will not engage the pruning based on worst UID.

Change-Id: I9f15c9a26938f1115eb75e9c28ddb073e7680e06
2015-04-22 11:53:29 -07:00
Mark Salyzyn
81b3eabc49 logd: class hierarcy for Uid and Pid statistics.
Add EntryBase and EntryBaseDropped base classes for statistical
entries to inherit from. Abstract add(), subtract() and drop()
methods to common LogBufferElement in each for entry policy decisions.
Some move of details out of LogStatistics.cpp and place them into
LogStatistics.h. Add statistical add(), subtract() and
drop() methods to hash table to call entries for policy.

Bug: 19608965
Change-Id: Ib8a33a8fe28871ef165d1632c6546a5c606231e8
2015-04-21 10:54:34 -07:00
Mark Salyzyn
5720d2c168 logd: Statistics headers
Answer to the question "Bytes or Lines?"

Change-Id: I352737265aeac63ea8d89e778d4222a9123bdf07
2015-04-21 10:54:34 -07:00
Mark Salyzyn
2c9d909a00 logd: better drop message merging
- Former algorithm anlo coalesced adjacent records
- New algorithm maintains a hash list of all drop
  records and coalesces them all.

Bug: 20334069
Bug: 20370119
Change-Id: Idc15ce31fc1087c2cfa39da60c62feade8b88761
2015-04-20 12:58:54 -07:00
Mark Salyzyn
202e153f94 logd: propagate ::log status
Add a return value for the ::log() methods, this allows
us to optimize the wakeup for the readers to only occur
when the log message is actually placed.

This is for a future where we may dedupe identical log
messages, filter out log messages, and certainly if we
filter the messages out with an internal logd check of
__android_log_is_loggable().

Change-Id: I763b2a7c29502ab7fa0a5d5022c7b60244fcfde4
2015-04-15 19:43:28 -07:00
Mark Salyzyn
56c6575da7 Merge "logd: syscall optimization" 2015-04-15 14:45:24 +00:00
Mark Salyzyn
c32afdf913 logd: pidToUid incorrect
Change-Id: I9b0e655780924db125568179771e57b01e80aaae
2015-04-14 13:07:29 -07:00
Mark Salyzyn
ae76923839 logd: disable worst uid prune for events buffer
There is some usage statistics that would be hurt by pruning by UID,
since _all_ usage statistics come from system_server. In other words
we expect it to be chatty. Until we formulate and evaluate a better
(eg: per-tag?) filtration mechanism, lets hold off pruning by UID.

Bug: 19608965
Change-Id: Iddd45a671e13bdcf3394c20919ad1f2e4ef36616
2015-04-10 15:45:10 -07:00
Mark Salyzyn
1a01f963ff Revert: "logd: default off by-UID spam filter"
With "logd: inject first UID by log buffer message" we can
remove the FUD introduced by having the UID spam filter on

This reverts commit 4141cb2391

Bug: 19608965
Bug: 14469172
Change-Id: Ifdc20b099e0e426546525b11c1dfe8cc0f830a02
2015-04-10 15:45:10 -07:00
Mark Salyzyn
ab0dcf6828 logd: annotate worst-UID pruned entries
- internal dropped entries are associated by prune by worst UID
  and are applied by UID and by PID
- track dropped entries by rewriting them in place
- merge similar dropped entries together for same UID(implied),
  PID and TID so that blame can more clearly be placed
- allow aging of dropped entries by the general backgound pruning
- report individual dropped entries formatted to reader
- add statistics to track dropped entries by UID, the combination
  of statistics and dropped logging can track over-the-top Chattiest
  clients.

Bug: 19608965
Change-Id: Ibc68480df0c69c55703270cd70c6b26aea165853
2015-04-10 15:45:08 -07:00
Mark Salyzyn
c6637859c2 logd: Build Breakage
a change slipped in from a rebase conflict, repairing.

Change-Id: Ib6479f88fb044f37b6721035c2f7cc75577c0411
2015-04-08 16:09:28 -07:00
Mark Salyzyn
08739ba71f logd: uidToName improvement
- read packages.list to acquire package names
- hijack the reinit handler as a privileged worker

Bug: 19608965
Change-Id: If7becb34354d6415e5c387ecea7d4109a15259c9
2015-04-08 14:47:54 -07:00
Mark Salyzyn
720f6d1d55 logd: Add Pid statistics
- Optional class of statistics for PID
- Enhance pidToName
- Enhanced uidToName
- Enhance pidToUid
- template sort and iteration

Bug: 19608965
Change-Id: I04a1f02e9851b62987f9b176908134e455f22d1d
2015-04-08 14:37:32 -07:00
Nick Kralevich
58ba58a97c logd: Don't embed a flexible array member within another struct
C (but not C++) has a concept of a flexible array member, which
is documented at https://gcc.gnu.org/onlinedocs/gcc/Zero-Length.html .
Using a flexible array member indicates that the structure is
really a header for a variable length object.

In logd's case, the variable length structure android_event_string_t
was embedded within another structure called
android_log_event_string_t. This makes gcc's __builtin_object_size()
function really confused. When compiling with C++,
__builtin_object_size(android_log_event_string_t.payload.data, 1)
would return 0, whereas if you compiled the code with C, the same
call would (properly) return -1.

Code which does automatic bounds checking, such as the proposed
patch at https://android-review.googlesource.com/145411 , will
cause problems for logd if this syntax is used.

Don't try to embed a variable length structure within another
structure. This doesn't appear to be valid C nor C++, and
while it's worked, it seems problematic.

Instead, inline the structure so it's one big happy structure.

Change-Id: I8ac02b7142a4f6560f5f80df2effcf720f9896fc
2015-04-07 10:12:20 -07:00
Elliott Hughes
bcc2b5f44a Remove LOCAL_ADDITIONAL_DEPENDENCIES in cases where it's not needed.
Change-Id: I720b8ef1050da45a7833adef8219b6acb2cf3a38
2015-04-02 14:31:07 -07:00
Mark Salyzyn
e3aeeeeccc logd: syscall optimization
- prset(PR_SET_NAME) call once
- No need to call getuid(), should be AID_LOGD

Change-Id: I4dde0b178bc84e711b355cd7677b0dbf905a0634
2015-04-01 19:41:59 +00:00
Mark Salyzyn
801bcecbb5 logd: missing include for string.h
LogCommand.cpp gets string.h inherited from
private/android_filesystem_config.h it should
not rely on this in the future. The intent is
to move fs_config function into libcutils and
thus deprecate any need for string.h in this
include file.

Bug: 19908228
Change-Id: Iaf3a77298b56efd8004300b17e9a1faafad5b08b
2015-04-01 11:18:42 -07:00
Nick Kralevich
a15db51bbf libaudit: limit to 5 selinux denials per sec
watchdog is triggering on shamu. This may be due to an excessive
number of SELinux denials. Drop the limit from 20/sec to 5/sec.

Bug: 19950451
Bug: 19949988
Change-Id: I979f11e17c241ff2ebda4dec9694ef441dc5d0ed
2015-03-26 14:04:13 -07:00