Commit graph

131 commits

Author SHA1 Message Date
Mark Salyzyn
bd1ef90448 logd: filter on __android_log_is_loggable
(cherry pick from commit e59c469fa8)

- Default level when not specified is ANDROID_LOG_VERBOSE
  which is inert.

Bug: 20416721
Bug: 19544788
Bug: 17760225
Change-Id: Icc098e53dc47ceaaeb24ec42eb6f61d6430ec2f6
2015-06-15 07:41:03 -07:00
Mark Salyzyn
3a1ff5ab65 Merge "Lower the priority of the threads in logd/logcat." into mnc-dev 2015-06-09 19:42:45 +00:00
Riley Andrews
d98f4e8af5 Lower the priority of the threads in logd/logcat.
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:36:45 -07:00
Mark Salyzyn
03196c9c75 logd: build breakage
(cherry pick from 3e21de2915)

OPEN_BRACKET_SPACE comparison always false

Change-Id: I1ff4288b4b79a49702727d3a8b8c8f179f500951
2015-06-08 14:57:07 -07:00
Mark Salyzyn
df5902c4f3 logd: fix kernel logline stutter
(cherry pick from commit 2c3b300fd8)

- 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 their log messages.

Change-Id: Ibfb56b32047da3d6513db059ca6edad0f0105168
2015-06-08 13:55:14 -07:00
Mark Salyzyn
c1e9d6dada logd: filters remove leading expire messages and rate
(cherry pick from commit 047cc0729f)

- 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 10:20:55 -07:00
Mark Salyzyn
6f1457adc5 logd: switch to unordered_map from BasicHashtable
(charry pick from commit 511338dd57)

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-04 11:03:37 -07:00
Mark Salyzyn
49ed105fd9 init.rc: logd: Add logpersistd (nee logcatd)
(cherry pick from commit 100658c303)

- 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:28:36 -07:00
Mark Salyzyn
42ac34f740 logd: test modernization
(cherry pick from commit 62d6a2a921)

Bug: 19603976
Change-Id: Ie920c128e7e6a436fea7a96c7d68bc39e13a2ad4
2015-06-01 14:27:02 -07:00
Mark Salyzyn
222f8c3ac7 logd: whitelist should not preserve expire messages
(cherry pick from commit c5bf3b8304)

Change-Id: I56275c73191b96aa21e7b4049d401e1f44211f9b
2015-06-01 14:27:02 -07:00
Mark Salyzyn
fbf96b55d9 logd: KISS & fix preserve a day
(cherry pick from commit 5921276a16)

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 14:27:02 -07:00
Mark Salyzyn
d4bdb7df9b logd: deal with sloppy leading expire messages
(cherry pick from commit 5392aac95d)

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 14:27:02 -07:00
Mark Salyzyn
94a811ab19 logd: worst-UID only to preserve a day
(cherry pick from commit 833a9b1e38)

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 10:03:11 -07:00
Mark Salyzyn
654904f0f9 logd: Add TID statistics
(cherry pick from commit 17ed6797df)

Bug: 19608965
Change-Id: Ifbf0b00c48ef12b5970b9f9f217bd1dd8f587f2c
2015-05-13 09:23:01 -07:00
Mark Salyzyn
66091f11f4 logd: Cleanup
(cherry pick from commit 7718778793)

- Android Coding Standard for Constructors
- Side effects NONE

Change-Id: I2cda9dd73f3ac3ab58f394015cb810820093d47b
2015-05-13 09:22:56 -07:00
Mark Salyzyn
a1aacb71f3 logd: Add klogd
(cherry pick from commit ae4d928d81)

- 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-13 09:22:45 -07:00
Mark Salyzyn
ff32f3c774 logd: Add Tag statistics
(cherry pick from commit 344bff4391)

- 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 15:34:56 -07:00
Mark Salyzyn
4fba28671b logd: pidToName deficiency
(Cherry pick from commit aa43ae2268)

any logging in zygote permanently sets the pidToName

Change-Id: I0b8fdc96fb5965a04d4dc4293c39815beef5eb8e
2015-05-12 13:06:25 -07:00
Mark Salyzyn
9bdc064720 logd: uidToName add dex2oat UID
(cherry pick from commit 023f51f360)

- 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-12 09:55:02 -07:00
Nick Kralevich
6de7a06afb 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.

(cherrypick of commit 9667a66019)

Change-Id: I05e85cce0a792d05aa557fcc614c0fc019c15014
2015-05-11 15:43:25 -07:00
Mark Salyzyn
8b22c293a0 logd: class hierarcy for Uid and Pid statistics.
(Cherry pick from commit 81b3eabc49)

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-05-07 10:01:39 -07:00
Mark Salyzyn
95108f1844 logd: improve details on chatty records
(Cherry pick from commit 21fb7e0b75)

- 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 15:25:12 -07:00
Mark Salyzyn
5a9d33ee1c logd: reduce chance of dropped 1 messages
- do not time out at 1 second if drop has count of less than 4

(Cherry picked from commit 35173a9ac5)

Bug: 20334069
Bug: 20370119
Change-Id: I787cb553dfab5ed71abd6ed72b63de675f834e0c
2015-04-30 13:24:59 -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
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
Mark Salyzyn
317843decf logd: statistics: missing comma
regression from statistics rewrite series resulted in build breakage

Change-Id: I71b532b23437b9b5f3af47b18c9110f3d7dda48a
2015-03-20 13:46:00 -07:00
Mark Salyzyn
97c1c2beee logd: optimize statistics
- Go back to basic requirements
- Simplify
- use hash tables to minimize memory impact

Bug: 19608965
Change-Id: If7becb34354d6415e5c387ecea7d4109a15259c8
2015-03-20 12:31:23 -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
Mark Salyzyn
ccbadc6be0 logd: report reinit
Bug: 19681572
Change-Id: I343b9d108f064f87df79512a0fdf1b35513c3136
2015-03-12 20:38:53 +00:00
Mark Salyzyn
11e55cb9c1 logd: add reinit command
- respond to SIGHUP
- respond to logd command "reinit"
- respond to logd --reinit
- reopens files on /data, eg: re-read of persistent properties

Bug: 19681572
Change-Id: Iadac58e6653f027cb7355497bd675eef376ce0a8
2015-03-12 12:24:47 -07:00
Mark Salyzyn
95b467888c logd: build cleanup
- Hard code the "auditd" event tag

Change-Id: I5f76fd286628be5c0ca819e8ed775648c0d2fa44
2015-03-09 10:02:51 -07:00
Mark Salyzyn
4ed16b4381 Revert "logd: Add minimum time bucket statistics"
This forward port reverts
    commit e457b74ce6

No longer as necessary once we add
    liblog: Instrument logging of logd write drops
Although this provided an indication of how close statistically we
were to overloading logd it is simpler to understand fails thus to
hunt and peck a corrected value for /proc/sys/net/unix/max_dgram_qlen

Change-Id: I2b30e0fc30625a48fd11a12c2d2cc6a41f26226f
2015-03-04 13:21:41 -08:00
Mark Salyzyn
29eb57066c logd: use <endian.h>
Change-Id: Iba843c054ea4fbe1a26c7821b5613fdb5e8001a1
2015-03-04 13:21:41 -08:00