Commit graph

545 commits

Author SHA1 Message Date
nickrose
653d49a245 Add logd CTS tests to VTS
Follow-up to  Change-Id: Id52ac1639447276171006c33bdfa7b4e6c874745

Test: make vts
Change-Id: Ibeb5082439ada49a6eccd6fb699e466ca71730c9
2017-07-10 11:17:38 -07:00
Steven Moreland
f73510e78d Merge "logd + liblogd to Android.bp" am: c997cd64dc am: f7a68f02d5
am: 25982a424b

Change-Id: I08172e23da0b58054380754b6db7c7e62069c2d9
2017-06-30 19:49:16 +00:00
Steven Moreland
f7a68f02d5 Merge "logd + liblogd to Android.bp"
am: c997cd64dc

Change-Id: I3cdc65fec1cd8487da86621a3381692ccd641756
2017-06-30 19:40:45 +00:00
Treehugger Robot
c997cd64dc Merge "logd + liblogd to Android.bp" 2017-06-30 19:32:41 +00:00
Steven Moreland
fca20d8aa1 logd + liblogd to Android.bp
Test: boot, adb logcat produces output
Change-Id: I89e7f9a19e139d3f5a71040b1555d01913946b85
2017-06-29 09:29:36 -07:00
Jaesung Chung
43dd866e08 Merge "logd-unit-tests: make sure use unsigned types when reading le" am: 31f2c81755 am: b9a1ff14ae
am: fe361ae7b3

Change-Id: I3b798c547772bf28f0ba00dfbf0a02b0712f9179
2017-06-19 00:28:29 +00:00
Jaesung Chung
fe361ae7b3 Merge "logd-unit-tests: make sure use unsigned types when reading le" am: 31f2c81755
am: b9a1ff14ae

Change-Id: I2a780305fca0143ec863d1736d6ff74ff222eef2
2017-06-19 00:23:19 +00:00
Jaesung Chung
23f1d09b74 logd-unit-tests: make sure use unsigned types when reading le
The get4LE method needs to use unsigned types since the sign char values
can lead to producing wrong values.

Bug: 62599757
Test: passes all test cases of logd-unit-tests.
Change-Id: Ifaf83533d847ea4fbe0cd46a978f4dabbfa7df8d
2017-06-16 17:45:37 +09:00
Guang Zhu
44a4ab854e add component metadata tag to CTS liblog test acses
Bug: 36140955
Bug: 35360169
Test: new unit test to ensure that all modules have this field
Change-Id: Ifb7a14817265b4624f1dc6414b547c86aafcf4ac
2017-06-05 23:17:50 +00:00
Mark Salyzyn
b463a37a97 Merge "logd: remove start filtration from flushTo (part deux)" am: 2623b6c55a am: b8f2089d91
am: fa685b1638

Change-Id: Ic933d9d763e8677ac3f5fab4d68f12160b737f5b
2017-05-19 17:08:12 +00:00
Mark Salyzyn
206ed8e2d6 logd: remove start filtration from flushTo (part deux)
We have already searched for the start point, the start filter check
is paranoia that removes out-of-order entries that we are undoubtably
interested in.  Out-of-order entries occur under reader pressure, as
the writer gets pushed back from in-place sorted order and lands it
at the end for the reader to pick it up.  If this occurred during a
batch run or a logger thread wakeup, the entry could be filtered out
and never output to the reader.

We have to treat exact finds for start in the list as terminal when
we search as they represent restarts, depending on the fact that it
is impossible to have the exact same time reported in two log entries
or requested from a batched reader.  This does break down if a log
entry has xxxxxx000 nanoseconds reported, we fix that by making sure
we never log such a case and slip it by a ns.

Found one case where logcat.tail_time* tests failed which was fixed
with this adjustment.

Test: gTest logd-unit-tests, liblog-unit-tests and logcat-unit-tests
Bug: 38046067
Bug: 37791296
Bug: 38341453
Change-Id: I4dd2e2596dd67b8d602160dd79661e01805227a9
2017-05-19 07:15:38 -07:00
Mark Salyzyn
87265fd5bb Merge "Revert "logd: remove start filtration from flushTo"" am: 8cfd2971ec am: f111b04f15
am: ef53957a7e

Change-Id: I50d342511a3e2b3762c90c1f8e7e912ac21012fd
2017-05-17 21:48:55 +00:00
Mark Salyzyn
eb45db2cf4 Revert "logd: remove start filtration from flushTo"
Regressed by introducing too much overlap in the results.

This reverts commit 982ad208b5.

Bug: 38341453
Change-Id: I9d630a6b9f3e464f523424b640090f7e268da9bd
2017-05-17 19:55:12 +00:00
Mark Salyzyn
4cc6519741 Merge "logd: remove start filtration from flushTo" am: c8c49988b1 am: 27d54dd4ac
am: 8ab4f5eafc

Change-Id: I700220b3db7c84de51053b818e4e597552b68c80
2017-05-16 15:27:24 +00:00
Mark Salyzyn
982ad208b5 logd: remove start filtration from flushTo
We have already searched for the start point, the start filter check
is paranoia that removes out-of-order entries that we are undoubtably
interested in.  Out-of-order entries occur under reader pressure, as
the writer gets pushed back from in-place sorted order and lands it
at the end for the reader to pick it up.  If this occurred during a
batch run or a logger thread wakeup, the entry could be filtered out
and never output to the reader.

Found one case where logcat.tail_time* tests failed which was fixed
with this adjustment.

Test: gTest logd-unit-tests, liblog-unit-tests and logcat-unit-tests
Bug: 38046067
Bug: 37791296
Change-Id: Icbde6b33dca7ab98348c3a872793aeef3997d460
2017-05-15 15:13:20 -07:00
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