Commit graph

61 commits

Author SHA1 Message Date
Mark Salyzyn
61e9ce6709 logd: add getEventTag command and service
Will register a new event tag by name and format, and return an
event-log-tags format response with the newly allocated tag.
If format is not specified, then nothing will be recorded, but
a pre-existing named entry will be listed. If name and format are
not specified, list all dynamic entries. If name=* list all
event log tag entries.

Stickiness through logd crash will be managed with the tmpfs file
/dev/event-log-tags and through a reboot with add_tag entries in
the pmsg last logcat event log. On debug builds we retain a
/data/misc/logd/event-log-tags file that aids stickiness and that
can be picked up by the bugreport.

If we detect truncation damage to /dev/event-log-tags, or to
/data/misc/logd/event-log-tags, rebuild file with a new first line
signature incorporating the time so mmap'd readers of the file can
detect the possible change in shape and order.

Manual testing:

Make sure nc (netcat) is built for the target platform on the host:
$ m nc

Then the following can be used to issue a request on the platform:
$ echo -n 'getEventTag name=<name> format="<format>"\0EXIT\0' |
> nc -U /dev/socket/logd

Test: gTest logd-unit-test --gtest_filter=getEventTag*
Bug: 31456426
Change-Id: I5dacc5f84a24d52dae09cca5ee1a3a9f9207f06d
2017-02-02 14:24:18 -08:00
Treehugger Robot
1fa079b255 Merge "Revert "logd: trailing spaces in log statistics"" 2016-12-20 18:16:00 +00:00
Mark Salyzyn
d966e22680 Revert "logd: trailing spaces in log statistics"
Caused +/- field data to land under the Pruned column

This reverts commit 0adcc3e3e8.

Test: manual
Bug: 30118730
Change-Id: Ic75ce3a90baded19f3efc0cc77474fe5d9a8accd
2016-12-19 15:06:37 -08:00
Mark Salyzyn
3296291cff logd: add android::sizesTotal() function
Test: gTest liblog-unit-tests, logd-unit-tests and logcat-unit-tests
Bug: 31456426
Change-Id: I6fb6cd589227fc43d22f9336e01f1bf7e3feb24c
2016-12-19 08:00:16 -08:00
Mark Salyzyn
a2c022257c logd: record multiple duplicate messages as chatty
If a series of messages arrive from a single source with identical
message content payload, then suppress them and generate a chatty
report.  The checking is done on a per log id basis.

This alters the assumption that chatty messages are always at the
oldest entries, they now show up in the middle too.  To address this
change in behavior we print the first line, a chatty reference
which internally takes little space, then the last line in the series.

This does not conserve processing time in logd, and certainly has no
impact on the long path of formatting and submitting log messages from
from the source, but it may contribute to memory space and signal to
noise savings under heavy spammy loads.

Test: gTest liblog-unit-tests, logd-unit-tests & logcat-unit-tests
Bug: 33535908
Change-Id: I3160c36d4f4e2f8216f528605a1b3993173f4dec
2016-12-15 16:31:51 -08:00
Jeff Sharkey
dff44709cf Define range of GIDs for cached app data.
To support upcoming disk usage calculation optimizations, this change
creates a new GID for each app that will be used to mark its cached
data.  We're allocating these unique GIDs so that we can use
quotactl() to track cached data on a per-app basis.

This change also tightens up the implementation of both the cache
and shared GID calculation to ensure that they stay inside the valid
ranges, and includes tests to verify.

Test: builds, boots, tests pass
Bug: 27948817
Change-Id: Ie4377e5aae267f2da39a165888139228995987cb
2016-12-13 13:28:08 -07:00
Mark Salyzyn
0eeb06b932 utils: Add FastStrcmp.h
Move existing fast<str*cmp> templates for general use, pulled from
the implementation used in logd that dealt with speed through cache
locality and subroutine call mitigation.  Rename to fastcmp.

Test: logd-benchmarks and based on manual profiling from the past
Bug: 31456426
Change-Id: Ic62f4a437fc3e06ffdeaae73a6f34e197957a6b0
2016-12-09 12:40:17 -08:00
Mark Salyzyn
6d981af120 logd: report statistics memory overhead
Add in to the Total Overhead the amount of storage we are
using to hold on to the statistics.

Test: see that the Total Overhead accounts for about 100K
Bug: 31942525
Change-Id: Ibe241c0bccc5a9df52395802338c8a7fc3b64104
2016-11-04 07:43:16 -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
9af33ee78c logd: report logging memory overhead
On 64 bit system, calculates to roughly 80 bytes of metadata and
list overhead for each entry.

In unit test example, we report 3388987 bytes of logging data and
overhead total, showmap reports 4652K of dirty data. We still want
to account for the remainder (fragmentation, other sources of
internal allocations etc).

Test: see values and check math
Bug: 31942525
Change-Id: I75f3162ce691faf1ae5a5dec18939fea535ede7e
2016-10-05 15:32:40 -07:00
Mark Salyzyn
807e40ecc9 liblog: logd: Add android_lookupEventTag_len()
Allows us to mitigate the impact of MAP_PRIVATE and copy on write by
calling android_lookupEventTag_len instead of android_lookupEventTag,
and delaying the copy on write impact to the later.  We return a
string length in a supplied location along with the string pointer
with android_lookupEventTag_len(const EventTagMap* map, size_t* len,
int tag).  The string is not guaranteed to be nul terminated.  Since
android_lookupEventTag() called even once can cause the memory
impact, we will mark it as deprecated, but we currently have no
timeframe for removal since this is a very old interface.

Add an API for __android_log_is_loggable_len() that accepts the non
null terminated content and fixup callers that would gain because the
length is known prior to the call either in the compiler or at
runtime.  Tackle transition to android_lookupEventTag_len() and
fixup callers.

On any application that performs logging (eg: com.android.phone)

/proc/<pid>/smaps before:

xxxxxxxxxx-xxxxxxxxxx rw-p 00000000 fd:00 463 /system/etc/event-log-tags
Size:                 20 kB
Rss:                  20 kB
Pss:                   1 kB
Shared_Clean:          0 kB
Shared_Dirty:         20 kB
Private_Clean:         0 kB
Private_Dirty:         0 kB
Referenced:            0 kB
Anonymous:            20 kB
AnonHugePages:         0 kB
Swap:                  0 kB
SwapPss:               0 kB
KernelPageSize:        4 kB
MMUPageSize:           4 kB
Locked:                0 kB
VmFlags: rd wr mr mw me ac

/proc/<pid>/smaps after:

xxxxxxxxxx-xxxxxxxxxx rw-p 00000000 fd:00 1773 /system/etc/event-log-tags
Size:                 20 kB
Rss:                  20 kB
Pss:                   1 kB
Shared_Clean:         20 kB  (was 0kB)
Shared_Dirty:          0 kB  (was 20kB)
Private_Clean:         0 kB
Private_Dirty:         0 kB
Referenced:           20 kB  (was 0kB)
Anonymous:             0 kB  (was 20kB)
AnonHugePages:         0 kB
Swap:                  0 kB
SwapPss:               0 kB
KernelPageSize:        4 kB
MMUPageSize:           4 kB
Locked:                0 kB
VmFlags: rd wr mr mw me ac

Added liblog-unit-tests --gtest_filter=liblog.event_log_tags to
check for Shared_Clean: to not be 0 and Anonymous: to be 0 for
all processes referencing event-log-tags.  Which can include multiple
references to /system/etc/event-log-tags and future possible refs to
/data/misc/logd/event-log-tags and /dev/event-log-tags.  We want
failure messages to help point to errant code using the deprecated
interface.

This change saves 1/4MB of memory or more on a typical system.

Test: gTest liblog-unit-tests
Bug: 31456426
Change-Id: I9e08e44d9092bd96fe704b5709242e7195281d33
2016-10-03 11:08:34 -07:00
Mark Salyzyn
6a06694a61 logd: Worst Tag filter enabled for events buffer
- Add drop logistics to TagTable
- replace uid references to a key reference since it
  is an UID for most buffers, but a TAG for the
  events and security buffer
- template the find worst entry mechanics into LogFindWorst class

Bug: 30118730
Change-Id: Ibea4be2c50d6ff4b39039e371365fed2453f17a2
2016-07-15 14:58:17 -07:00
Mark Salyzyn
0adcc3e3e8 logd: trailing spaces in log statistics
Bug: 30118730
Change-Id: I8cccbc1da2cf8168ec9cf12f07df4cafef076558
2016-07-15 11:00:44 -07:00
Mark Salyzyn
b8a95bd3c9 logd: switch from android_ids to getpwuid
Bug: 27999086
Change-Id: I7f4e68b21f58789b4dcada04f9c27f5722940c02
2016-04-14 15:14:46 +00:00
Mark Salyzyn
bec3c3def9 logd: Add worst pid of system filter
- Add a new statistic that reports per pid and log_id for AID_SYSTEM
- Add a new pruning filter ~1000/! boolean
- Use this new statistic to prune on worst pid within AID_SYSTEM

Bug: 26029733
Bug: 21615139
Bug: 22855208
Change-Id: Iab5dd28f807dcf03d276372853883f3b6afa8294
2015-12-29 09:32:35 -08:00
Mark Salyzyn
ee3b838e13 logd: statistics per-pid filter
Primarily gives access to the Chattiest TIDs and TAGs
associated with a pid.

Has a secondary effect of allowing us to pull out the
command line, comm and in some cases the associated
PACKAGE for a specific pid while the logs are still
present even if the executable is gone.

Bug: 26029733
Bug: 21615139
Change-Id: I1ea63165a680a9318360579b70b1512078ed5682
2015-12-18 13:17:37 -08:00
Mark Salyzyn
083b037c07 logd: liblog: logcat: Add LOG_ID_SECURITY
- Largish commit, buffer and access controls done together
- Add LOG_ID_SECURITY binary content log
- Add "default" meta buffer
- allow LOG_ID_SECURITY only from AID_SYSTEM and AID_ROOT UID & GID
- Use __android_log_security() to gate logging
- Add __android_log_security_bwrite() native access to security
  logging.
- Add liblog.__security_buffer end-to-end gTest

Bug: 26029733
Change-Id: Ibcf5b4660c17c1aa6902c0d93f8ffd29c93d9a93
2015-12-08 16:46:29 -08:00
Mark Salyzyn
c723df805a logd: statistics report chatty effective percentage
Report the ESTIMATED instantaneous percentage decrease or increase
that an UID has to the logs as a result of the chatty filtration.

Bug: 22855208
Change-Id: If1e77afb81a2739a72b39bc7c57071763c1d64d8
2015-10-30 14:54:17 -07:00
Mark Salyzyn
58b8be8906 logd: correct for number of elements in prune
Chatty logs would distort the average log size by elevating the
elements, but not the size. Add statistical collection for the
number of elements that report chatty, and subtract that from
the number of elements to improve the pruning estimate. Pick
minElements as 1% rather than 10% of the total with this more
accurate number of elements, to a minumum of 4.

Bug: 24511000
Change-Id: I3f36558138aa0b2a50e4fac6440c3a8505d95276
2015-10-13 13:43:16 -07:00
Mark Salyzyn
758058ffd8 logd: object layer format statistics
Simplify table generation by placing the line and header formatting
into each type's (UID, PID, TID) object. Switch to const return
values for the ownership passing functions (*ToName() functions
and methods). Use longer variable names to reduce confusion.

Switch from LINES To NUM for pruned column as that more accurately
reflects what is dropped since one entry can contain several lines.

Bug: 22855208
Change-Id: Ib110dce98a68cf5f844eb30f8a192a1f691eeba2
2015-10-05 09:27:57 -07:00
Mark Salyzyn
ddda212faa logd: optimize code hotspots
Discovered that we had a few libc hotspots. Adjust code to generally
reduce or nullify the number of calls to malloc, free, strlen,
strcmp, strncmp, memcmp & strncasecmp. Total gain looks to be about
3% of logd's processing time. malloc still contributes to 3%, but all
others are now total 0.5%.

Bug: 23685592
Change-Id: Ife721121667969260cdb8b055524ae90f5911278
2015-10-02 16:45:22 -07:00
Mark Salyzyn
73160acc5c logd: switch asprintf to std::string
Bug: 23350706
Change-Id: I715cdd4563a09de3680081947a3439f0cac623be
2015-08-20 10:32:16 -07:00
Mark Salyzyn
decbcd9c41 logd: statistics switch to std::string
Bug: 23350706
Change-Id: I5564898c4f67b8fcc43cee64604855f789409482
2015-08-20 10:25:57 -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
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
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
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
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
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
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
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
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
Elliott Hughes
a744b05984 Add missing <malloc.h> and <string.h> includes.
Change-Id: Ia41756e607663d056e7d2fdd7ecbec7e5841a913
2015-01-28 11:37:57 -08:00
Mark Salyzyn
f48ea7c8dc logd: LogStatistics leak
- uid = -1 in subtract operation to match add

Change-Id: I7d0b85b5334c5264fd04309cb78e0c9aec0ad261
2014-10-06 22:43:56 +00:00
Mark Salyzyn
df5aa61f05 logd: kill(0,0) issue
- Recognize pid=0 as special case (kernel or pre-init sourced)
  and refrain from treating it in the general case.

Bug: 17526159
Change-Id: I74796043ac34753c6dd10018719ebc0bcd94e012
2014-10-06 22:43:46 +00:00
Mark Salyzyn
f5fc509589 logd: Add control statistics enable/disable.
- ro.build.type=user turn off statistics
- ro.config.low_ram=true turn off statistics
- logd.statistics override

Bug: 17526159
Bug: 17526187
Change-Id: I74796043ac34753c6dd10018719ebc0bcd94e00f
2014-10-06 22:42:47 +00:00
Mark Salyzyn
e72c6e4366 logd: cleanup
- simplify access and control exposure to class list
- indent
- compile warning
- Follow standard naming convention for variables and methods
- merge common fragments
- Side Effects: none

Change-Id: I74796043ac34753c6dd10018719ebc0bcd94e010
2014-10-06 22:42:07 +00:00
Chih-Hung Hsieh
634118e261 logd: fix format-extra-args warning.
Bug: 17409250
Change-Id: Id50ebb57754b12d69ed605d0e2901b8e05c607c6
2014-09-12 23:37:42 +00:00
Arseniy Antonov
c3ce224c62 Fix for parenthesis error
Added parentheses as it was suggested by compiler.
error: suggest parentheses around operand of '!' or change '&' to '&&' or '!' to '~' [-Werror=parentheses]

Change-Id: Ic3746d9804488411d10d460ddfda11f1fad8efef
Signed-off-by: Arseniy Antonov <arseniy.antonov@intel.com>
2014-09-03 17:29:20 +04:00