Commit graph

630 commits

Author SHA1 Message Date
Mark Salyzyn
e3587f612c Merge "logd: logcat --clear respect pruneMargin" am: 3d0186b97e am: daae7558e8
am: 96ab6a71fa

Change-Id: Ic52878dc55b1bc2ce277a2d2e34d854c6bfc136e
2017-05-15 20:40:47 +00:00
Mark Salyzyn
0878a7c167 logd: logcat --clear respect pruneMargin
While a reader is present, consider it a success, and not busy, if a
buffer is pruned down to pruneMargin plus one second of additional
margin of logspan.  If not busy, no need to trigger any mitigations
regarding the readers, or to report any errors.

Side Effects are we no longer mitigate the reader when performing
chatty filtration. This is a positive side effect because we were
getting --wrap wakeups that seemed premature.

Add kickMe() and isBusy() methods to ease maintenance and uniformity
of actions.

Test: gTest liblog-unit-tests, logd-unit-tests & logcat-unit-tests
Test: manual: 'logcat -b all -c' repeat in a loop, at various logging
      load levels, simultaneously 'logcat -b' all in another session.
Bug: 38046067
Change-Id: I3d0c8a2d416a25c45504eda3bfe70b6f6e09ab27
2017-05-15 07:01:42 -07:00
Mark Salyzyn
28034ce8ab Merge "logd: validate and fill in socket credentials" am: 17254f59a2 am: 1423041905
am: b3b67adafd

Change-Id: Id0f6c9df1a48215be1812e39903a55eeaccff969
2017-05-12 01:57:30 +00:00
Mark Salyzyn
db52ba299b Merge "logd: test: check sepolicy background rate before testing" am: 5a40c42877 am: 1961eab662
am: 5698594d8a

Change-Id: I6c6e5e08f01b23bedfeb90b3f39031b92a092f44
2017-05-12 01:55:23 +00:00
Mark Salyzyn
c4e4823b00 logd: validate and fill in socket credentials
- android::pidToUid() additional checking.  Make sure if we have to
  convert a PID to an UID that the parse of /proc/<pid>/status
  requires a trailing space after the number
- android::tidToPid() added, in the same vein as android::pidToUid().
- stats.tidToPid() added
- If no credentials, set PID to 0 and UID to DEFAULT_OVERFLOWUID
- If credentialed PID is 0, use stats.tidToPid()
- If credentialed UID is DEFAULT_OVERFLOWUID, use stats.pidToUid()

Test: remove +passcred from logd.rc for daemon and confirm very few
      UID=65534 or PID=0 cases actually show up
Bug: 37985222
Change-Id: I7d20506e70e67beb3043d1537cf9450ab58dc278
2017-05-11 12:21:02 -07:00
Mark Salyzyn
c51ecf9238 logd: test: check sepolicy background rate before testing
logd.sepolicy_rate_limiter_* tests can fail individually so join them
together into one test.  The new test logd.sepolicy_rate_limiter
fails as a group if the background sepolicy activity is too high, so
check it and report a warning that the test can fail as a result so it
can be forgiven during unit testing.  The failure remains as a VTS
performance threshold that requires investigation.

The test takes a total of 45 seconds to run, it was split up as this
approaches the 60 second test timeout on go/apct.

Test: gTest logd-unit-tests --gtest_filter=logd.sepolicy_rate_limiter
      (run in loop ensuring passes do not interfere with eachother)
Bug: 37791296
Change-Id: Ia865241f684c6b0de428702cbd5110dc17927c66
2017-05-11 17:16:30 +00:00
Mark Salyzyn
fa992c039d Merge "logd: add "+passcred" for logdw socket" am: cc22a8e5a2 am: 518f054bfd
am: ff04ade5e4

Change-Id: I924893609e80661631c506a41459070823e40b74
2017-05-09 01:11:41 +00:00
Mark Salyzyn
54d8ff1121 logd: add "+passcred" for logdw socket
Tell init to set SO_PASSCRED on the socket before bind() and handoff.

Test: gtest logd-unit-test --gtest_filter=logd.statistics right after boot
Bug: 37985222
Change-Id: I318969ee3241834e5326233aabd97e52ef505969
2017-05-08 16:19:48 -07:00
Mark Salyzyn
b48c99a93d Merge changes Ieb44fa8f,I01b26fe5 am: e1e3e20337 am: d8dc29df8e
am: b519cb5e14

Change-Id: I0154f15f4b8b0dc7216ee16bc3f9eeb79fc90458
2017-05-03 23:38:40 +00:00
Mark Salyzyn
d392ac160c logd: refine permissions to access /data/system/packages.list
Refine DAC security surrounding logd.daemon worker thread and add a
positive test for logd failure to access /data/system/packages.list.

- Add AID_PACKAGE_INFO to groups of worker thread.
- Move AID_SYSTEM to groups, setgid to AID_LOGD.
- Do not drop capabilities until after setting the uid and gids.
- Add a test that is part of logd.statistics test to check when
  packagelistparser appears broken.
- If /data/system/packages.list is encrypted, ensure we do not pick
  up the existing inode to ensure strong positive when finding access
  problems.
- Replace all occurrences of NULL with nullptr in gTest code for
  compliance with best practices.

Test: gTest logd-unit-tests --gtest_filter=logd.statistics
      (expect consistent failure, later CLs fix)
Bug: 37751120
Bug: 36645158
Change-Id: I01b26fe5e25203246ae432d272c8daa9c07cab54
2017-05-03 14:35:14 -07:00
Chenjie Luo
f5e8d05be5 Merge "Modularize logd." am: ab28acef76 am: c955d890de
am: e49500a041

Change-Id: I16c4c6eb7b13a98862a059e17d5c3703beec2370
2017-05-02 00:57:00 +00:00
Chenjie Luo
ab28acef76 Merge "Modularize logd." 2017-05-02 00:44:47 +00:00
Mark Salyzyn
b9f9b7c500 Merge "logd: CTS test" am: 16214f2955 am: fddaec1e2c
am: d492d04c45

Change-Id: I6a62d36aba23dd4c7ba8a9a3b9b6894df2d95a08
2017-05-01 17:01:59 +00:00
Chenjie Luo
fafea32468 Modularize logd.
Separates logd body into a static library liblogd and
virtualize LogBuffer::log to be in a new interface class
LogBufferInterface. User could have different implementation.

Bug: 37756450
Test: liblog-unit-tests, logd-unit-tests and logcat-unit-tests
with (b/37791296).
Change-Id: I1504ff0e992744001b5a2e9abd45692d1318a152
2017-04-28 17:30:25 -07:00
Mark Salyzyn
2bd06f2895 logd: CTS test
Utilize logd-unit-tests as a CTS test

Goal is to check if the kernel logger is enabled.

Test: run cts tests
Bug: 31772697
Change-Id: I6d80350f3e40aff095f81b6600c40dd7d376bd74
2017-04-28 13:50:56 -07:00
Mark Salyzyn
2d27e9d3a1 Merge "logd: add Chattiest LOG_TAG statistics" am: 8c437b95d3 am: a4015dce4c
am: 95a5521140

Change-Id: I5076d260182dff33ac94cd4103018179e77aaa91
2017-04-26 16:00:02 +00:00
Mark Salyzyn
f99a7d602a logd: add Chattiest LOG_TAG statistics
Report global LOG_TAG usage.

Switch NULL to nullptr and use const more accurately.

Test: gTest liblog-unit-tests, logd-unit-tests & logcat-unit-tests
Test: manual: inspect logcat -S results around 'Chattiest TAGs'
Test: logcat -b all -c ; logcat -b all -S ; then confirm clear
Bug: 37254265
Change-Id: I3696c0d8da3ba24f99f670aafba1e45f8cb3ab14
2017-04-24 16:04:03 -07:00
Mark Salyzyn
69c76c0c76 Merge "Revert "logd: add Chattiest LOG_TAG statistics"" am: 5002a48cee am: 74b66822d2
am: 614baba5fa

Change-Id: I25770538873723b6352675f8b04600eff843f5b8
2017-04-24 20:26:31 +00:00
Mark Salyzyn
afd7e70553 Revert "logd: add Chattiest LOG_TAG statistics"
This reverts commit 903156ddaa.

Test: compile
Bug: 37254265
Change-Id: If9af79684119861ceecf4f88a4a4c84f991b188a
2017-04-24 19:52:33 +00:00
Mark Salyzyn
0735206a83 Merge "logd: add Chattiest LOG_TAG statistics" am: 39aee46352 am: c26df4fa0f
am: ae1d2e0e83

Change-Id: I9c588b59b561e74ad186230e5ecd7df2e4dced92
2017-04-24 19:23:19 +00:00
Mark Salyzyn
903156ddaa logd: add Chattiest LOG_TAG statistics
Report global LOG_TAG usage.

Test: gTest liblog-unit-tests, logd-unit-tests & logcat-unit-tests
Test: manual: inspect logcat -S results around 'Chattiest TAGs'
Bug: 37254265
Change-Id: I32473a1d9131c87e4fb7841d5cc0ea9cc14c63cd
2017-04-21 15:55:10 -07:00
Mark Salyzyn
29c987e1ea Merge changes I6555c135,If5723ff4 am: d9982803ed am: b3259f39c2
am: 529be90503

Change-Id: I59734360708e09b1c12abd11b75f9e93dc61eb99
2017-04-20 17:57:04 +00:00
Mark Salyzyn
5643587311 Merge "logd: statistics add logspan" am: e32517d773 am: 2ad8ed5138
am: 58871c8338

Change-Id: I06639472b8f6252de7891d8e7f6485c558e73d64
2017-04-20 15:31:22 +00: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
ce24cd381a Merge changes Ie7a5303e,I2b3c2ac4 am: 3a052c42be am: 3bcb013833
am: 8295e39d4f

Change-Id: Ib8136516f65cf57e505c305ab1d95bf303ab4940
2017-04-19 23:38:13 +00:00
Mark Salyzyn
03bb7593e4 logd: statistics add logspan
Logspan down to the millisecond.  Show a percentage if trimmed by
Chatty messages, a subspan from the newest to the newest chatty in
the log buffer.  Sniff stats.add(elem), stats.subtract(elem) and
stats.dropped(elem) to generate the logspan data.

Test: gTest liblog-unit-tests, logd-unit-tests and logcat-unit-tests
Test: manual check Logspan statistics for being in range, added
      temporary internal instrumentation to confirm expectations.
Bug: 37254265
Change-Id: I09c0d9375d5580315543c747b37976f9eeb9e408
2017-04-19 09:18:51 -07:00
Mark Salyzyn
02dd2f42f8 logd: replace stats.add+stats.subtract with stats.addTotal
Replace stats.add(elem) + stats.subtract(elem) with a new more
efficient method stats.addTotal(elem).

Test: gTest liblog-unit-test, logd-unit-tests and logcat-unit-tests
Bug: 37254265
Change-Id: I2b3c2ac44209772b38f383ae46fe6c4422b542cf
2017-04-19 09:16:30 -07:00
Mark Salyzyn
642eb61aa1 Merge "logd: report log reader instantiation" am: 0ca7eec9b0 am: 7a8a048f56
am: b0bf71f166

Change-Id: Ia0e3abedff63270e9b874bb7c98010d4df14b28d
2017-04-19 00:00:10 +00:00
Mark Salyzyn
fa3add3364 logd: report log reader instantiation
Helpful instrumentation to determine who is waiting for logger data.

Test: manual
Bug: 37274132
Bug: 37378309
Change-Id: I14fb1d9d15ae413930121048b770852359f06682
2017-04-18 14:59:46 -07:00
Treehugger Robot
f358bed624 Merge "libcutils: compile with BOARD_VNDK_VERSION current" 2017-04-18 14:46:27 +00:00
Mark Salyzyn
ba83d8366c Merge changes Iec369a50,I3f9f8d56,I78959464,I72ea858e am: 6ad16cda19 am: 7b45da1006
am: 732f30ee8e

Change-Id: I2aaac98558b8717c7dc339eccaa3215f40c2575a
2017-04-18 14:33:57 +00:00
Steven Moreland
fc5d4345fa Merge "libcutils: compile with BOARD_VNDK_VERSION current" into oc-dev
am: 64639fd7dc

Change-Id: Ic30e207a89cf80f6f509f64f92ec9ee32cfaf3c1
2017-04-17 23:19:28 +00:00
Mark Salyzyn
24aa9a41e1 logd: instrument tests better for failure
Failure to open socket misbehaved and told us nothing.

Test: gTest logd-unit-tests
Bug: 37378309
Change-Id: Iec369a50ccb1027e96947465e90d9572c9f4047f
2017-04-17 15:10:26 -07:00
Mark Salyzyn
3614a0c5d4 logd: iterator corruption paranoia
Add checking for impossible(tm) scenarios within LogBuffer::flushTo:

1) When iterating through the log entries, check if the iterator
   returns two identical element references and break out of the loop.
2) Cap the maximum number of log entries we will skip while holding
   the iterator lock at 4194304, break out of the loop.

We print a message to the kernel logs if we hit these cases.

ToDo: Remove this paranoia at some future date.

Test: gTest liblog-unit-tests logcat-unit-tests and logd-unit-tests
Bug: 37378309
Change-Id: I789594649db14093238828b9f6d1daeca8b780c2
2017-04-17 15:10:26 -07:00
Mark Salyzyn
5836379b21 logd: regression in handling watermark boundary.
Deal with a regression introduced in commit
5a34d6ea43 (logd: drop mSequence from
LogBufferElement) where log_time was compared against nsec() time
miscalculating the watermark boundary.  When dealing with logcat
-t/-T, or any tail reading, add a margin to prune to back off by a
period of 3 seconds (pruneMargin).

Test: gTest liblog-unit-tests logcat-unit-tests and logd-unit-tests
Bug: 37378309
Change-Id: I72ea858e4e7b5fa91741ea84c40d2e7c3c4aa031
2017-04-17 15:10:26 -07:00
Steven Moreland
d73be1b96b libcutils: compile with BOARD_VNDK_VERSION current
- moved __android_log_is_debuggable to a new public header
    (log_properties.h)
- vendor version of sched_policy uses ALOG* instead SLOG*

Test: (sanity) liblog-unit-tests
Test: (sanity) libcutils_test (noting b/b/32972117, two tests continue
  to fail)
Test: system/core as a whole makes with BOARD_VNDK_VERSION := current
  now with no problems.
Test: boots/works on internal marlin
Bug: 33241851

(cherry picked from commit 1f83aa424f)

Merged-In: I5bc1f348dc0f0c8814bec5b5c3d2c52c825ab640
Change-Id: I5bc1f348dc0f0c8814bec5b5c3d2c52c825ab640
2017-04-17 14:44:17 -07:00
Steven Moreland
1f83aa424f libcutils: compile with BOARD_VNDK_VERSION current
- moved __android_log_is_debuggable to a new public header
    (log_properties.h)
- vendor version of sched_policy uses ALOG* instead SLOG*

Test: (sanity) liblog-unit-tests
Test: (sanity) libcutils_test (noting b/b/32972117, two tests continue
  to fail)
Test: system/core as a whole makes with BOARD_VNDK_VERSION := current
  now with no problems.
Test: boots/works on internal marlin
Bug: 33241851

Change-Id: I5bc1f348dc0f0c8814bec5b5c3d2c52c825ab640
2017-04-17 12:18:36 -07:00
Mark Salyzyn
f4dbbea20c Merge changes I596b8706,I262c0377,Iaf2bee97 am: 030b4d1b08 am: 3447f72d43
am: fa80674a19

Change-Id: I94bad3a2c64194c2377de4277c066bbd3030f823
2017-04-14 21:43:15 +00:00
Mark Salyzyn
030b4d1b08 Merge changes I596b8706,I262c0377,Iaf2bee97
* changes:
  liblog: allow event tags to include some punctuations
  liblog: logprint supports number of seconds time event field
  logcat: test: standardize rest() to let logs land when injecting
2017-04-14 21:33:23 +00:00
Mark Salyzyn
5bc976b112 Merge "logd: statistics truncate name" am: 42d524f73d am: 7f9719be48
am: 00c87bcf73

Change-Id: I81de78de58de4809004a42a3b352bd25780d5e05
2017-04-14 21:05:03 +00:00
Mark Salyzyn
5768d3d976 liblog: logprint supports number of seconds time event field
Add s to report time in seconds.  The time could be a period, duration
or monotonic, expanded to seconds, minutes, hours and days.  gTest has
to acquire a dynamic tag allocation as there are no users of this
feature yet.

Looking to the future, audio media logging has binary content similar
to the binary events structures Android logging uses and they have
a definition of a duration field in their internal binary logging, so
may be of use when we unify the logs.

Test: gTest logcat-unit-tests --gtest_filter=*.descriptive
Bug: 31456426
Change-Id: I262c03775983b3bc7b1b00227ce2bb2b0f357bec
2017-04-14 12:54:25 -07:00
Mark Salyzyn
f31ae3d666 logd: statistics truncate name
Prefix long truncated names with an ellipse (...). Shift left as
much as possible when doing so, but keep spaces between command
name and other tabular fields.

Test: manual/visual
Bug: 37254265
Change-Id: I185b1e121ba911a9410a8b6624e013d5a531962b
2017-04-13 16:33:20 -07:00
Hidehiko Abe
035224e3c5 Merge "Force set timezone to UTC in logd." am: 0de940c26d am: 5cadd1399b
am: 8becca0b44

Change-Id: Ib06e78dedd61899a65181bb00e4fd20c0c69f555
2017-04-13 07:33:28 +00:00
Hidehiko Abe
352476e118 Force set timezone to UTC in logd.
(cherry picked from commit c27f12a3d396f113c5ae09d2f2c8ff7de3f8b551)

logd assumes that it is running in UTC time zone.
However, if persist.sys.timezone is set at some point later,
that affects and confuses logd behavior.
To avoid such a case, this CL sets TZ to UTC, which overrides
the property's behavior.

Test: Ran CtsOsTestCases.
Test: gTest liblog-unit-tests, logd-unit-tests and logcat-unit-tests
Bug: 33566779
Change-Id: Ib9edd4cb06f019a33aaf8d77d33bd82fdbbda480
2017-04-12 14:33:17 -07:00
Mark Salyzyn
1d7a2c5c3e Merge "logd: test: logd.sepolicy* errors" am: ebc87c98e3 am: d7acf56639
am: ef3ee4008f

Change-Id: Iac8023896bb6f26f36965f44ef0ec899ec604271
2017-04-06 17:49:27 +00:00
Mark Salyzyn
bc1d2aeff9 logd: test: logd.sepolicy* errors
If setcon fails, try alternate setcon, and then if it still
fails call getcon to confirm if it is an OK sepolicy context
anyways.

Test: gTest logd-unit-tests --gtest_filter=logd.sepolicy*
Change-Id: Iaf20b8a1a4a7312247288e1879884a54893c15ae
2017-04-06 07:40:10 -07:00
Mark Salyzyn
5adcb3e3e7 Merge "logd: cap out-of-order entry search" am: b15882faab am: 1b559e2f8d
am: 3cb28fd064

Change-Id: I78eae5076547e541c09e0a8d9c684c9a3e358e57
2017-04-04 20:22:03 +00:00
Mark Salyzyn
775cd22222 logd: cap out-of-order entry search
Reduce the period we are willing to look back at for out-of-order
entries.  Cap the number of iterations we are willing to look back
for out-of-order entries to 300.

Test: gTest liblog-unit-tests, logd-unit-tests and logcat-unit-tests
Bug: 36875387
Bug: 36874561
Bug: 36861142
Change-Id: Icee289dfc0a37ccab9912dc8ab40a10ef3967b7a
2017-04-04 11:12:31 -07:00
Mark Salyzyn
0f92fdc5d6 logd: cap out-of-order entry search
Reduce the period we are willing to look back at for out-of-order
entries.  Cap the number of iterations we are willing to look back
for out-of-order entries to 300.

Test: gTest liblog-unit-tests, logd-unit-tests and logcat-unit-tests
Bug: 36875387
Bug: 36874561
Bug: 36861142
Change-Id: Icee289dfc0a37ccab9912dc8ab40a10ef3967b7a
2017-04-04 11:03:26 -07:00
Mark Salyzyn
8f066045a8 Merge changes Ic590c230,Ibd4be82b am: 3c013de8d8 am: 0b743b925e
am: f9785f5c4d

Change-Id: I35b260af5fe6ae0b205eebb661e789eaecea505f
2017-04-03 14:32:28 +00:00
Mark Salyzyn
005ee6480c Merge "logd: correctly label identical lines" am: a9b5a5e96a am: 41e44283d2
am: d599f97ee5

Change-Id: I3e97e596cbd88b7458007e04a882066a21869aa4
2017-04-03 14:32:16 +00:00
Mark Salyzyn
3c013de8d8 Merge changes Ic590c230,Ibd4be82b
* changes:
  logd: liblog benchmark check BM_log_overhead regression
  liblog: benchmark add BM_log_event_overhead_42 for a well known tag
2017-04-03 14:21:41 +00:00
Mark Salyzyn
b88ec1352f 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 15:13:07 -07:00
Mark Salyzyn
dd609d810b logd: strip out empty trailing iovec
If the last buffer has zero length, strip it out of the iovec
issued to SocketClient::sendDatav().

Test: gTest liblog-unit-tests, logd-unit-tests, logcat-unit-tests
Bug: 36497967
Change-Id: I8fc585bbec63402d0e818ff4c620fdd7edcc38dc
2017-03-31 15:12:29 -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
81ab11af67 logd: liblog benchmark check BM_log_overhead regression
Failed to acquire BM_log_print_overhead as it was renamed from
BM_log_overhead in commit 8f2492f582
(liblog: benchmark: Use local LOGGER_NULL frontend')

The test report would not clearly identify which entry was missing, or
unparsed, so unrolled the loop and incorporating the indexes by name
so that gTest failure report offers a much better clue to the problem.

Test: gTest logd-unit-tests --gtest=logd.benchmark
Bug: 36683634
Bug: 27405083
Change-Id: Ic590c230569871651fb716054ecf635385d0f8a2
2017-03-31 13:41:45 -07:00
Mark Salyzyn
046855b551 Merge "logd: strip out empty trailing iovec" am: 6b11faeb42 am: d749a054ff
am: 657ae57bf3

Change-Id: I522284e11471e9eb4db091275d5461860e8c2e4b
2017-03-28 15:18:43 +00:00
Mark Salyzyn
479c8c2e42 logd: strip out empty trailing iovec
If the last buffer has zero length, strip it out of the iovec
issued to SocketClient::sendDatav().

Test: gTest liblog-unit-tests, logd-unit-tests, logcat-unit-tests
Bug: 36497967
Change-Id: I8fc585bbec63402d0e818ff4c620fdd7edcc38dc
2017-03-27 15:49:24 -07:00
Mark Salyzyn
02ce4262dc Merge changes I96998c4b,I161bf03b am: dd0cd8d88f am: f17500474a
am: 77a1fa9070

Change-Id: I5b296f6c1b01a8b2dc51c7ebbd44d599a3aa49c1
2017-03-27 22:42:44 +00:00
Mark Salyzyn
1f46716f1c logd: last iterator initialized incorrectly
last should start with mLogElements.end() and be updated as
we iterate to find a matching time entry in the list. Since
it is impossible(sic) for a newer start time to be supplied
than the list, the incorrect iterator initialization should
be inconsequential, but if it ever happens this change will
behave correctly and dump nothing.

Test: gTest liblog-unit-tests, logd-unit-tests and logcat-unit-tests
Bug: 36536248
Bug: 36608728
Change-Id: I96998c4b713258f29d5db2e24a83ae562ddf3420
2017-03-27 21:26:13 +00:00
Mark Salyzyn
0484b3b575 logd: ASAN cleansing
A mixture of fixes and cleanup for LogKlog.cpp and friends.

- sscanf calls strlen.  Check if the string is missing a nul
  terminator, if it is, do not call sscanf.
- replace NULL with nullptr for stronger typechecking.
- pass by reference for simpler code.
- Use ssize_t where possible to check for negative values.
- fix FastCmp to add some validity checking since ASAN reports that
  callers are not making sure pre-conditions are met.
- add fasticmp templates for completeness.
- if the buffer is too small to contain a meaningful time, do not
  call down to log_time::strptime() because it does not limit its
  accesses to the buffer boundaries, instead stopping at a
  terminating nul or invalid match.
- move strnstr to LogUtils.h, drop size checking of needle and
  clearly report the list of needles used with android::strnstr
- replace 'sizeof(static const char[]) - 1' with strlen.

Test: gTest liblog-unit-test, logd-unit-tests & logcat-unit-tests
Bug: 30792935
Bug: 36536248
Bug: 35468874
Bug: 34949125
Bug: 34606909
Bug: 36075298
Bug: 36608728
Change-Id: I161bf03ba029050e809b31cceef03f729d318866
2017-03-27 13:32:57 -07:00
Mark Salyzyn
ea6bb2818a Merge changes I92cac83b,Ie897c40b am: 4278f71118 am: 898c8a6e51
am: 0508ebf9da

Change-Id: I3c639a37b5d5dfe2b7b5eac36ab0711fae0ae72d
2017-03-17 14:33:12 +00:00
Mark Salyzyn
5e001776f4 logd: wakeup wrap timeout if realtime changes drastically
--wrap flag in logcat translates directly to the mTimeout inside logd,
the value set is ANDROID_LOG_WRAP_DEFAULT_TIMEOUT defined in
<log/log_read.h> as 7200 or 2 hours.  For a non blocking read with
a selected timeout, the logger waits until either the log buffer is
about to 'wrap' and prune the log entry, or at the specified timeout.
Non blocking in the logger context means that when there are no more
log entries, the socket is closed.

clock_gettime(CLOCK_REALTIME) is UTC 1970 epoch *NIX time. Is only
affected for time updates, not timezone or daylight savings time.
If there is a large user initiated time change, both the log entries
and the timeout mentioned above really get called into question, so we
trigger a release of the logs for clarity.  This is so that the log
reader can handle the disruptively updated time, and can immediately
check the local time if necessary.

The logger has a 5 second window for entries to land in time sorted
order into the logging list.  This should offer the log reader some
differentiation between logging order sequence for monotonically
increasing time, and sequence order in the face of user initiated time
adjustments that break monotonicity.

This change is about major time adjustments that can cause Fear,
Uncertainty or Doubt about log entries.  By returning, immediate action
can be taken, rather than having to comb through the logs with less
details about the time disruptions in hand.  The least it can do is
record what we have, and restart the call with a new tail time and
timeout.

Test: gTest liblog-unit-tests logcat-unit-test logd-unit-tests
Bug: 35373582
Change-Id: I92cac83be99d68634ffd4ebd2f3a3067cfd0e942
2017-03-17 14:17:55 +00:00
Mark Salyzyn
09d663229f logd: cap how far back in-place sort will go to 5 seconds
Add some deterministic behavior should the user change the hour
backwards when altering the device time, prevent sort-in-place
and cause the logger to land the new entries at the end.

Do not limit how far kernel logs can be sorted.

Test: gTest liblog-unit-tests logd-unit-tests logcat-unit-tests
Bug: 35373582
Change-Id: Ie897c40b97adf1e3996687a0e28c1199c41e0d0c
2017-03-17 14:17:38 +00:00
Mark Salyzyn
f883804b56 Merge changes I2a073293,Ia55ef8b9,I79a385fc am: 82b5c619b8 am: 5a0afe7d27
am: 9f8a97ed0b

Change-Id: Iae26c69eb4ffdfdc3b20b1a841bfc67d768f33f1
2017-03-16 17:19:47 +00:00
Mark Salyzyn
3b941d457b logd: continue search out-of-order entries timestamp tail
Regression from commit 8e8e8db549

For liblogcat reader -t or -T <timestamp> tail requests, continue
search for pertinent out-of-order entries for an additional 30 seconds
back into logging history to find a more inclusive starting point.

For example, if you have an out of order landing like
[..., 3, 6, 1, 8, 2, 5] and ask for 3 you used to get only 5, and now
you get 3, 6, 8, 5 as 'expected'

Test: gTest liblog-unit-tests logd-unit-tests logcat-unit-tests
Bug: 35373582
Change-Id: I2a0732933fa371aed383d49c8d48d01f33db2a79
2017-03-16 16:57:53 +00: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
1d84f0b2af logd: ensure LogBufferElement mSequence is monotonic
- Improves accuracy of -t/-T '<timestamp>' behavior when out of order
  arrival of entries messes with mSequence as the list will now have
  monotonic sequence numbers enforced.
- Out of order time entries still remain because of reader requiring
  the ability to receive newly arrived old entries.
- -t/-T '<timestamp>' can still quit backward search prematurely
  because an old entry lands later in the list.
- Adjust insert in place algorithm from two loops of scan placement
  and then limit against watermark, into one that does all of that
  plus iteratively swap update the sequence numbers to set
  monotonicity.  Side effect will be that the read lock (which is
  actually the LogTimes lock) will be held longer while we search
  for a placement above the youngest LogTimes watermark.  We need
  to hold the read (LogTimes) lock because we may be altering the
  sequence numbers affecting -t/-T '<timestamp>' search.

Test: gTest logd-unit-tests liblog-unit-tests logcat-unit-tests
Bug: 35373582
Change-Id: I79a385fc149bac2179128b53d4c8f71e429181ae
2017-03-16 08:13:43 -07:00
Andreas Gampe
401a19845c Merge "Logd: Fix wrong parameters" am: 913ad12543 am: 0daaa5aec8
am: a8fbb17d2d

Change-Id: Ib3099519c8387e47591037ff9e09f253ca25667f
2017-03-15 15:53:44 +00:00
Treehugger Robot
913ad12543 Merge "Logd: Fix wrong parameters" 2017-03-15 15:38:14 +00:00
Andreas Gampe
34450d70c5 Logd: Fix wrong parameters
Better keep the right order, or ASAN will complain when you read
out of bounds.

Bug: 36234128
Test: m
Test: m && m SANITIZE_TARGET=address
Test: Sanitized device boots without ASAN crashes
Change-Id: Ifc09cb0ece6835d2b636a3ad2128e09ca9aa45c9
2017-03-14 20:43:43 -07:00
Evgenii Stepanov
03fc2fedd7 Fix heap-buffer-overflow detected by ASAN.
Bug: 34949125
Bug: 34606909
Test: Make sure Android boots when built with SANITIZE_TARGET='address'
Change-Id: I9c004e806f2025098aa72228284b05affd2c2802
2017-03-14 14:47:25 -07:00
Mark Salyzyn
1598fe03b9 Resolve merge conflicts of e40a08509 to master
Test: gTest liblog-unit-tests logd-unit-tests logcat-unit-tests
Bug: 35373582
Bug: 34949125
Bug: 34606909
Change-Id: If6f3f138974913039dd49f2451bad6e413d6e2e1
2017-03-13 15:44:57 -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
Alex Shlyapnikov
589f4e7a66 Fix heap-buffer-overflow detected by ASAN.
Bug: 34949125
Bug: 34606909
Test: Make sure Android boots when built with SANITIZE_TARGET='address'
Change-Id: I9c004e806f2025098aa72228284b05affd2c2802
2017-02-23 16:15:05 -08:00
Mark Salyzyn
9f27c6985d Merge "logd: add getEventTag id= command" am: 3e3aaca4c3 am: b7987ce8c4
am: 9bd6e36a9f

Change-Id: I5995e912626100462dd5a706d5e3af7d92488155
2017-02-22 23:33:55 +00:00
Mark Salyzyn
407537f798 logd: add getEventTag id= command
This is the precursor for "Plan B" recovery when access to
/dev/event-log-tags is blocked to untrusted zones.  Also
deals with mitigating issues with long-lived mappings that
do not update /dev/event-log-tags when dynamically changed.

Test: gTest logd-unit-test --gtest_filter=logd.getEventTag_42
Bug: 31456426
Bug: 35326290
Change-Id: I3db2e73763603727a369da3952c5ab4cf709f901
2017-02-22 14:16:31 -08:00
Greg Hartman
a6754dd558 Fix read past end of malloc block in logd
Bug: 35412453
Test: Local build
Change-Id: I0f9dee84ef689b042926b6b48abf0caeaa784add
2017-02-16 18:30:45 +00:00
Mark Salyzyn
c9e5f37166 liblog: add android_lookupEventTagNum
android_lookupEventTagNum added.  Adds support for creating a new
log tag at runtime, registered to the logd service.

Tested on Hikey, all services stopped, shell only access, CPUs not
locked (there is enough repeatability on this platform).

$ /data/nativetest64/liblog-benchmarks/liblog-benchmarks BM_lookupEventTagNum

                          iterations      ns/op
Precharge: start
Precharge: stop 231
NB: only Tag matching, linear lookup (as reference, before unordered_map)
BM_lookupEventTagNum         1000000       1017
NB: unordered_map with full Tag & Format lookup, but with Tag hashing
BM_lookupEventTagNum         2000000        683
NB: with full Tag & Format hash and lookup for matching
BM_lookupEventTagNum         2000000        814
NB: only Tag matching (Hail Mary path)
BM_lookupEventTagNum         5000000        471

Because the database can now be dynamic, we added reader/writer locks
which adds a 65ns (uncontended) premium on lookups, and switch to
check for an allocation adds 25ns (either open code, or using
string_view, no difference) which means our overall speed takes 90%
as long as the requests did before we switched to unordered_map.
Faster than before where we originally utilized binary lookup on
static content, but not by much.  Dynamic updates that are not cached
locally take the following times to acquire long path to logd to
generate.

BM_lookupEventTag           20000000         139
BM_lookupEventTag_NOT       20000000         87
BM_lookupEventFormat        20000000         139
BM_lookupEventTagNum_logd_new   5000         335936
BM_lookupEventTagNum_logd_existing 10000     249226

The long path pickups are mitigated by the built-in caching, and
the public mapping in /dev/event-log-tags.

SideEffects: Event tags and signal handlers do not mix
Test: liblog benchmarks
Bug: 31456426
Change-Id: I69e6489d899cf35cdccffcee0d8d7cad469ada0a
2017-02-02 15:21:15 -08:00
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
Mark Salyzyn
b5b8796785 logd: multiple identical do not report expired
Report multiple identical chatty messages differently than for
regular expire chatty messages.  Multiple identical will
report identical count, while spam filter will report
expire count.

This should reduce the expected flood of people confused
but chatty messages in continuous logcat output.

Test: gTest logd_unit_tests --gtest_filter=logd.multiple*
Change-Id: Iad93d3efc6a3938a4b87ccadddbd86626a015d44
2017-01-24 11:02:18 -08:00
Mark Salyzyn
c3c06294e5 logd: test: switch to /data/backup/ for sepolicy avc injection
Resolve issues seen on continuous testing frame:

- statistics test, info instead of fail on missing radio log data.
- sepolicy switch from /data/misc/logd/ to /data/backup/ as the
  directory we access(2) to inject sepolicy violations.  The key here
  is we are still root, but we are in u:r:shell:s0, and the directory
  does not provide us DAC access (0700 system system) so we trigger
  the pair dac_override and dac_read_search on every try to get past
  the message de-duper.  /data/misc/logd is not always there, until
  logpersist is enabled, but /data/backup is always there.
- a stricter signature of '): avc: denied'
- put in a looser threshold for sepolicy_rate_limiter_spam test.

Test: gTest logd-unit-tests --gtest_filter=logd.sepolicy*
Bug: 34454758
Change-Id: I28ce4fdb51dc4869944e3253b593ce222d16ec98
2017-01-20 09:42:02 -08:00
Mark Salyzyn
247d682fe1 logd: sepolicy dynamic rate limiting
Processing overhead for selinux violation messages is costly. We want
to deal with bursts of violations, but we have no intent of allowing
that sustained burst to go unabated as there is a cost of processing
and battery usage.

Tunables in libaudit.h are:

AUDIT_RATE_LIMIT_DEFAULT 20        /* acceptable burst rate      */
AUDIT_RATE_LIMIT_BURST_DURATION 10 /* number of seconds of burst */
AUDIT_RATE_LIMIT_MAX     5         /* acceptable sustained rate  */

Since we can only asymptotically handle DEFAULT rate, we set an upper
threshold of half way between the MAX and DEFAULT rate.

Default kernel audit subsystem message rate is set to 20 a second.
If sepolicy exceeds 125 violation messages over up to ten seconds
(>=~12/s), tell kernel audit subsystem to drop the rate to 5 messages
a second.  If rate drops below 50 messages over the past ten seconds
(<5/s), tell kernel it is ok to increase the burst rate back to 20
messages a second.

Test: gTest logd-unit-tests --gtest_filter=logd.sepolicy_rate_limiter_*
Bug: 27878170
Change-Id: I843f8dcfbb3ecfbbe94a4865ea332c858e3be7f2
2017-01-04 14:46:58 -08:00
Treehugger Robot
5badada997 Merge "LogAudit.cpp: replace newlines with spaces in audit messages" 2017-01-03 22:21:37 +00:00
Nick Kralevich
2e58867771 LogAudit.cpp: replace newlines with spaces in audit messages
Some kernels have a bug which causes a newline to show up in audit
messages. The embedded newlines cause one message to look like two due
to prefix controls.

Replace any newlines with spaces. Duplicate spaces are further
consolidated in code immediately after this newly added code.

Test: create an audit message with a newline, and watch it be cleaned up.
Bug: 27878170
Change-Id: Id90c29ab9e10d3be96f51403b0293622d782422a
2017-01-03 12:39:28 -08:00
Mark Salyzyn
ce80da3018 logd: Add support for ro.logd.auditd.[main|events]
log selinux audit messages boolean (true or false, default true)
selection for logging destinations:

ro.logd.auditd - turn on logd.auditd to pick up violations.
ro.logd.auditd.dmesg - to the kernel log.
ro.logd.auditd.main - to the "main" log buffer.
ro.logd.auditd.events - to the "events" log buffer.

We used to also read logd.auditd.dmesg and persist.logd.auditd.dmesg
which do not get refreshed when /data mounts internally.  This is a
confusing state as these properties will be read after a logd crash
and restart, adjusting the behavior of the logger.  Same can be said
for logd.auditd as well.  Drop reading these other parameters.

Test: manual set r/o parameters, stop/start logd to confirm behavior
Bug: 33969000
Bug: 27878170
Change-Id: I1a6bb4a903074c9aa7b227cf583a0094d49cbefd
2017-01-03 09:44:42 -08:00
Mark Salyzyn
1736c4866c logd: gtest: logd.timeout socket does not clean up properly
Until the socket ages out, it sticks around and gets reused in
subsequent tests affecting the outcome of those tests.  We opt
to run logd.timeout in a forked and isolated process to keep
these conditions from interfering.

Adjusted benchmark execute to only run the tests we are
interested in to improve the time it takes to run.

Commented some areas of code to make them easier to maintain.

Test: gTest logd-unit-tests success
Bug: 33962045
Change-Id: Ic1b98bc4a2d7e8927f1a87628e3bcc368c9cf8ce
2016-12-29 12:59:22 -08:00
Mark Salyzyn
684bdb576d logd: LogBufferElementKey use uint32_t for uid
Test: gTest liblog-unit-tests, logd-unit-tests & logcat-unit-test
Change-Id: Icae34b1fa0b3df0a45ad175ec81aaf232f322f38
2016-12-21 12:16:46 -08:00
Treehugger Robot
2ead17196c Merge "logd: trailing spaces in log statistics (part deux)" 2016-12-20 18:16:15 +00:00
Treehugger Robot
1fa079b255 Merge "Revert "logd: trailing spaces in log statistics"" 2016-12-20 18:16:00 +00:00
Treehugger Robot
27425fd80d Merge "logd: sum liblog tag messages" 2016-12-19 23:43:48 +00:00
Treehugger Robot
9fa0215e15 Merge "logd: correct duplicate message state machine" 2016-12-19 23:43:23 +00:00
Mark Salyzyn
b545e1c9e3 logd: trailing spaces in log statistics (part deux)
Test: manual
Bug: 30118730
Change-Id: Iafda6f95e1b1377649e01868c81c0056c116e01b
2016-12-19 15:06:42 -08: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
1dfb4de436 logd: sum liblog tag messages
As an extension to the duplicate multiple message filtering, special
case liblog tagged event messages to be summed.  This solves the
inefficient and confusing duplicate message report from the DOS attack
detection such as:

liblog: 2
liblog: 2
liblog: 2
liblog: 2
liblog: 3

which would result in:

liblog: 2
chatty: ... expire 2 lines
liblog: 2
liblog: 3

And instead sums them and turns them all into:

liblog: 11

liblog messages should never be subject to chatty conversion.

Test: liblog-benchmarks manually check for coalesced liblog messages
      and make sure they do not turn into chatty messages.
      Instrumented code to capture sum intermediates to be sure.
Bug: 33535908
Change-Id: I3bf03c4bfa36071b578bcd6f62234b409a91184b
2016-12-19 14:03:38 -08:00
Mark Salyzyn
8f83a35511 logd: correct duplicate message state machine
Inspection turned up that for the case of three identical messages,
the result would be a stutter of the first message only.  Added
comments to describe the state machine, incoming variables, outcoming
and false condition outputs, for proper maintenance in the future.

Test: gTest liblog-benchmarks BM_log_maximum* and manually check
      for correct midstream chatty messages,
Bug: 33535908
Change-Id: I852260d18a484e6207b80063159f1a74eaa83b55
2016-12-19 14:01:45 -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
10f4044341 Merge "system/core: replace EVENT_TAG_MAP_FILE with NULL"
am: 9bfd9f558b

Change-Id: Ief7fcc4f7dd8086186b38c091fed626560ca7215
2016-11-29 19:46:50 +00:00
Mark Salyzyn
1179eb8048 system/core: replace EVENT_TAG_MAP_FILE with NULL
NULL represents system default.  In the future, NULL could represent
static and dynamic tags, which can come from multiple files based on
implementation details in the liblog library.

Test: gTest logd-unit-tests & liblog-unit-tests
Bug: 31456426
Change-Id: I0e3d296de81ca299ae63d7b83781639ee67ec298
2016-11-21 11:13:02 -08:00
Mark Salyzyn
2cfd0e08e9 Merge "logd: add EXIT command"
am: 16300f192b

Change-Id: Idd68cfba26f8fcc928db4fe2483d30e5d4f49a59
2016-11-18 16:10:23 +00:00
Mark Salyzyn
c8749d5108 logd: add EXIT command
Debugging aid. Allows us to run:

$ cat -n '<STUFF>\0EXIT\0' | nc -U /dev/socket/logd

and the pipeline will exit once done. Without the EXIT command
we will have to <CTRL+C> out to terminate the pipeline. This is
necessary since Android's netcat command does not support the -q
feature, and having the EXIT command is faster and cleaner anyways.

Test: manual as noted above.
Bug: 31456426
Change-Id: I65333358188db85e2eb1bb6a14deed1565826ac4
2016-11-17 14:42:33 -08:00
Mark Salyzyn
809dee506e Merge "libcutils: move cutils/files.h to cutils/android_get_control_file.h"
am: 8c41e791ed

Change-Id: Ifbc00285da734859d590153a7c6cfc8e51c014f9
2016-11-17 15:33:02 +00:00
Mark Salyzyn
52bd37e633 libcutils: move cutils/files.h to cutils/android_get_control_file.h
files.[h|cpp] is bound to be abused with junk, replace with
android_get_control_file.[h|cpp]. Plus some sundry cleanup.

Test: gTest libcutils-tests, logd-unit-tests, liblog-unit-tests,
      logcat-unit-tests and init_tests
Bug: 32450474
Change-Id: Ibd4a7aa4624ea19a43d1f98a3c71ac37805d36b5
2016-11-16 15:56:56 -08:00
Mark Salyzyn
49893142ec logd: report last prune memory overhead
am: b0672290e3

Change-Id: I4b060ad4427e24170cc7a3aeae7aa9f6643ba8d6
2016-11-04 20:57:16 +00:00
Mark Salyzyn
1970d994b6 logd: report statistics memory overhead
am: 6d981af120

Change-Id: I69376a8783867a21f0cd85eea4b299f3d2c81a95
2016-11-04 20:57:12 +00:00
Mark Salyzyn
f8ba9eb1a3 logd: if eng build, be a bit more permissive about failures
am: 107e29ac1b

Change-Id: I85ebcae9f756bf2feb79e6d77ea63ad0b2ff4829
2016-11-04 14:43:47 +00:00
Mark Salyzyn
21dbb8aece logd: start logd service in logd uid
am: 77fdb22cf6

Change-Id: I38d93fb74ea4f37ee137f78063d082637b8fd68a
2016-11-04 14:43:36 +00:00
Mark Salyzyn
3d2c4829a0 logd: auditd + klogd control CAPS
am: d2b3291ffa

Change-Id: I7d8fd4a7df7ceffd90e8eaab03861ae426cbf35b
2016-11-04 14:43:31 +00:00
Mark Salyzyn
83a40b0eb2 logd: drop capabilities in logd --reinit and logd.daemon
am: d8f01807b8

Change-Id: I17f06463258e95a6cc83242cc8a8d4bb0ccb4907
2016-11-04 14:43:26 +00:00
Mark Salyzyn
c65f2ca81f logd: drop libminijail dependency
am: f0b8e1bce6

Change-Id: I968916b41f82fa1cbe4f7ac37dc75c938a9c1627
2016-11-04 14:43:21 +00:00
Mark Salyzyn
b0e425abc4 logd: start logd services in logd gid
am: 5b44340acb

Change-Id: Id9f27660a09e640815071dac85ed4bac78172886
2016-11-04 14:43:17 +00:00
Mark Salyzyn
b0672290e3 logd: report last prune memory overhead
An estimate based on chatty impact for all known pids, uids and tags
and per log id if applicable, calculate the maximum last pruned
watermark iterator map usage and add to the Total Overhead.

Test: Confirm that the Total Overhead change is negligable.
Bug: 31942525
Change-Id: Icd2e9bc0747c3376ca0e9c90aa110c103529d98f
2016-11-04 07:43:16 -07: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
1259d9ea4b logd: inherit android_get_control_file()
am: e0b8ccd1a3

Change-Id: I7b6fc3898d2e69542309fe120122849579f91f22
2016-11-04 14:43:07 +00:00
Treehugger Robot
fc3e90689e Merge changes I432016e2,Id208b11b,Ia6a38729,Icdaf9e35,I842a7a64, ...
* changes:
  logd: if eng build, be a bit more permissive about failures
  libcutils: klog inherit android_get_control_file("/dev/kmsg")
  logd: start logd service in logd uid
  logd: auditd + klogd control CAPS
  logd: drop capabilities in logd --reinit and logd.daemon
  logd: drop libminijail dependency
  logd: start logd services in logd gid
  logd: set executable's capabilities in file system
  logd: inherit android_get_control_file()
  init: service file keyword
  libcutils: add android_get_control_file()
  libcutils: add android_get_control_socket() test
2016-11-04 14:38:23 +00:00
Mark Salyzyn
cb2314e5bd Merge "logd: switch to using arraysize() from libbase macros"
am: fc08963f85

Change-Id: If17fd9389ec65f379fa42096e835be2ed667f703
2016-11-03 22:14:34 +00:00
Treehugger Robot
fc08963f85 Merge "logd: switch to using arraysize() from libbase macros" 2016-11-03 22:07:42 +00:00
Mark Salyzyn
d1687af980 logd: clear DUMPABLE
am: 6a70ded7bf

Change-Id: I4bcfb53d9c4a13761c80a8f2070320c85b486b0b
2016-11-03 21:01:45 +00:00
Mark Salyzyn
107e29ac1b logd: if eng build, be a bit more permissive about failures
Allows us some leaway to investigate logd issues on eng builds

Test: gTests logd-unit-tests, liblog-unit-tests and logcat-unit-tests
      Manual on eng builds, bad logd.rc to fake permission issues
Bug: 32450474
Change-Id: I432016e29e5601d67c502076ead941cecdcbebe7
2016-11-03 13:34:27 -07:00
Mark Salyzyn
77fdb22cf6 logd: start logd service in logd uid
Test: gTest logd-unit-tests, liblog-unit-tests and logcat-unit-tests
      Manual inspect grep '^Cap' /proc/<tid>/status for correct capabilities
Bug: 32450474
Change-Id: Ia6a3872901969a789d4309d410dbfd5f5d17b3ce
2016-11-03 13:34:27 -07:00
Mark Salyzyn
d2b3291ffa logd: auditd + klogd control CAPS
Test: gTest logd-unit-tests, liblog-unit-tests and logcat-unit-testsa
Bug: 32450474
Change-Id: Icdaf9e352e86c9e140928509201da743004aeedb
2016-11-03 13:34:27 -07:00
Mark Salyzyn
d8f01807b8 logd: drop capabilities in logd --reinit and logd.daemon
Test: gTest logd-unit-tests, liblog-unit-tests and logcat-unit-tests
Bug: 32450474
Change-Id: I842a7a64f0ba695acef66caf54270f9475c9f9ac
2016-11-03 13:34:27 -07:00
Mark Salyzyn
f0b8e1bce6 logd: drop libminijail dependency
Use libcap instead of libminijail.  Set CAP_SETGID before setgroups,
then clear it afterwards.

Test: gTest logd-unit-tests, liblog-unit-tests and logcat-unit-tests
Bug: 32450474
Change-Id: I2ed027fd5efd95f76b1dd4c5791bae5f2ea94c28
2016-11-03 13:34:27 -07:00
Mark Salyzyn
5b44340acb logd: start logd services in logd gid
logd - start as root:logd+system+readproc
logd-reinit - start as logd:logd

ToDo: start as logd:logd+system+readproc (libminijail)
Test: gTest logd-unit-tests, liblog-unit-tests and logcat-unit-tests
Bug: 32450474
Change-Id: I42c806ca1730a7f9eb9e34f064ae31a2ef9fc678
2016-11-03 13:34:27 -07:00
Mark Salyzyn
e0b8ccd1a3 logd: inherit android_get_control_file()
Setup and then collect from the environment /proc/kmsg and /dev/kmsg
file descriptors. Do not do so for logcat --reinit.

Test: gTest logd-unit-tests, liblog-unit-tests and logcat-unit-tests
Bug: 32450474
Change-Id: Ied537ca561fcd4e71a9ad9c57398a23ba23f6ced
2016-11-03 13:34:27 -07:00
Mark Salyzyn
c8d3194098 logd: switch to using arraysize() from libbase macros
Test: logd-unit-tests, liblog-unit-tests & logcat-unit-tests
Bug: 32450474
Change-Id: Iacdc4677f2c83898a7812c2af2c36e7ff7d92764
2016-11-03 12:27:29 -07:00
Mark Salyzyn
6a70ded7bf logd: clear DUMPABLE
Do not allow anyone to see logd memory.

Test: gTest logd-unit-tests, liblog-unit-tests and logcat-unit-tests
Bug: 32450474
Change-Id: Ic7377efcb7e1d3cd91b50741061037a0fb589045
2016-11-03 11:20:59 -07:00
Mark Salyzyn
2bbb6d65d5 Merge "logd: getTag() functional for chatty entries"
am: fbe0b45544

Change-Id: I20705e262af4ed7c36616459b1f37dadca294277
2016-10-26 14:17:28 +00:00
Mark Salyzyn
60636fa872 logd: getTag() functional for chatty entries
getTag() becomes invalid when entry is dropped because mMsg
disappears to save space; but the per-tag spam filter depends on it
still being valid.  Conserve space in LogBufferElement by optimizing
the size of the fields, then add a new mTag field that is set in the
object constructor.  Add an isBinary() method.

SideEffects: save 12 bytes/log message overhead on 64-bit.
Test: define DEBUG_CHECK_FOR_STALE_ENTRIES and look for stale entries
Bug: 32247044
Change-Id: Iaa5f416718a92c9e0e6ffd56bd5260d8b908d5c0
2016-10-25 21:48:33 +00:00
Mark Salyzyn
54977be62b Merge "logd: address code fragility in last watermarks"
am: dd153ef247

Change-Id: I4efa93b98429528cc0445eed55cfd593ba2c24d8
2016-10-24 23:12:55 +00:00
Treehugger Robot
dd153ef247 Merge "logd: address code fragility in last watermarks" 2016-10-24 23:09:15 +00:00
Mark Salyzyn
28fcac705b liblog: logd: logcat: Split out log/logger.h into public and private.
am: aeaaf81c2c

Change-Id: I124c69673c30bb5f2259849792ed4ca99f4d6b60
2016-10-24 22:53:11 +00: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
8fcfd85acc logd: address code fragility in last watermarks
Do not make the assumption that if worstPid is set, that the log
buffer id is not LOG_ID_EVENTS or LOG_ID_SECURITY. Add comments
to prevent future over-optimization based on this assumption.

Make sure we reset mLast[id] = begin() when we mark it unset, but
tell optimizer this is an _impossible_ path.

SideEffects: drop two branches in all erase calls, gain an unordered
             find() on an empty list for events and security buffers.
Test: gTest logd-unit-tests, liblog-unit-test & logcat-unit-tests
Bug: 32247044
Change-Id: Ic156ca2253c050c28021cedf48bedaf7bd692c09
2016-10-24 10:43:52 -07:00
Mark Salyzyn
ead6503178 Merge "logd: mLastWorstPidOFSystem crash"
am: c75a32aae3

Change-Id: Ief8a0847243a0f2661192325efac5ce965dde92a
2016-10-21 20:17:59 +00:00
Mark Salyzyn
fa07f9dc4b logd: mLastWorstPidOFSystem crash
mLastWorstPidOfSystem is filled with iterator references
that are not from AID_SYSTEM to aid the performance. But
we only clear entries from the list during erase if they
are from AID_SYSTEM. Remove the filter check in erase so
the stale references will be removed.

The conditions that caused this failure are difficult to
reproduce and are rare.

Test: gTests logd-unit-tests, liblog-unit-tests and logcat-unit-tests
Bug: 32247044
Bug: 31237377
Change-Id: Ie405dd643203b816cac15eef5c97600551cee450
2016-10-21 10:20:55 -07:00
Mark Salyzyn
8a7297a09f Merge "system/core: preparation to pull back interfaces from android/log.h"
am: 27d2d49f48

Change-Id: I604bb1d4cf62636663fa92e3d14a55887dbcae23
2016-10-20 18:03:57 +00:00
Mark Salyzyn
cfd5b080af system/core: preparation to pull back interfaces from android/log.h
Point to log/log.h where necessary, define LOG_TAG where necessary.
Accept that private/android_logger.h is suitable replacement for
log/logger.h and android/log.h.

Correct liblog/README

Effectively a cleanup and controlled select revert of
'system/core: drop or replace log/logger.h' and
'system/core: Replace log/log.h with android/log.h'.

Test: compile
Bug: 30465923
Change-Id: Ic2ad157bad6f5efe2c6af293a73bb753300b17a2
2016-10-20 08:11:39 -07:00
Mark Salyzyn
1bd1e570c6 Merge "logd: Use private interfaces for buffer size properties"
am: 6da6d37c81

Change-Id: I05ec69d785c9df9c9a397947ad9f6bd4c915c078
2016-10-19 14:34:51 +00:00
Mark Salyzyn
f10e273790 logd: Use private interfaces for buffer size properties
Test: gTest logd-unit-tests, liblog-unit-tests and logcat-unit-tests
Bug: 31750617
Change-Id: I692577cfdf4bf8c93616f32df4b56786918aef1c
2016-10-18 09:49:51 -07:00
Mark Salyzyn
f606721b59 logd: use __android_log_is_debuggable()
am: 5740a46e4e

Change-Id: Idddc3c174b152b90dca915f7bf0cef654b41be3d
2016-10-18 16:46:06 +00:00
Mark Salyzyn
5740a46e4e logd: use __android_log_is_debuggable()
Test: gTest logd-unit-tests
Bug: 27566046
Bug: 31456426
Change-Id: I9faf88263fe62ce5bba80dc2cb928e6dbe73dbb2
2016-10-14 08:04:21 -07:00
Mark Salyzyn
c377c40531 Merge "logd: report logging memory overhead" am: d3754ff696 am: 386630f4ce
am: 1f6e063e06

Change-Id: Ia7daa52e3d3cf68dd5dcd70ba83f8aa38ae6f8da
2016-10-06 14:26:46 +00: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
Mohan Srinivasan
96eba22338 Merge "liblog: logd: Add android_lookupEventTag_len()" am: 093951a230 am: aed39f1f3d
am: 2acb41b46c

Change-Id: Ifd5da3780cf05863b71fad9583b1b83f4962b46f
2016-10-03 22:47:51 +00: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
c0a92b4a94 logd: logcat: Replace log/log.h with android/log.h am: 0dd4431072 am: 0f76f04072
am: a8d0a46956

Change-Id: I7c43316eef4ae12e666ea6a0126a38ac571dd41e
2016-09-30 22:17:47 +00:00