Select a low rate-limit to cut down on logspam and resulting
performance regressions.
Functionally reverts 247d682fe1
(logd: sepolicy dynamic rate limiting) and sets a static low
rate-limit. Before 247d682f, the limit was statically set to 20.
247d682f continued to support 20, but if sustained dropped the limit
to 5. This revert leaves us at 5 so as not to impact performance.
Test: /data/nativetest/logd-unit-tests/logd-unit-tests \
--gtest_filter=logd.sepolicy_rate_limiter
[ PASSED ] 1 test.
Bug: 71538411
Change-Id: I6c92f4ba825cc24beb8f1f1b79258fa8097c837b
Cts tests can run in appdomain, which have access to /data/backup/
which leads to zero injection of sepolicy signal to check the logd
and kernel rate limiter. Switch to /data/drm/ as a better choice
to inject a sepolicy denial either due to dac_override or
dac_read_search because owned by the drm uid and gid, or due to
create sepolicy denial to u:object_r:drm_data_file:s0 to all but
select services.
Test: gTest
Bug: 65843095
Change-Id: I2d72b1407a930c270636a206066d2d15fdec2f77
liblog concurrent printf tests now check every write succeeds.
logd timeout_negative tests exits as soon as one run succeeds.
Test: CTS tests till pass.
Change-Id: I9a166a0abcb8b9aa5c055c35c5dccf30616a4e24
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
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
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
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
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
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
Switch _all_ file's coding style to match to ease all future changes.
SideEffects: None
Test: compile
Bug: 35373582
Change-Id: I470cb17f64fa48f14aafc02f574e296bffe3a3f3
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
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
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
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
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
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
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
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
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
Should use android/log.h instead of log/log.h as a good example
to all others.
Test: Compile
Bug: 26552300
Bug: 31289077
Change-Id: If4c9711eb57267d4707b03d54a932af9de241b13
- check hdr_size to make sure it is in the expected range
from sizeof entry_v1 to entry (entry_v4).
- alter msg() method to report NULL on invalid hdr_size
- alter all users of msg() method.
Bug: 30947841
Change-Id: I9bc1740d7aa9f37df5be966c18de1fb9de63d5dd
Allow socket send syscall to terminate after 32 seconds if reader
stalled because of memory pressure allocating new network buffers
Add a gTest to catch regressions, add security buffer to log_dump
Bug: 27242723
Change-Id: Idaa6699d9d284e7f5f723ae0e76b3d6aa3371489
Add parsing to recognize optional chatty effective
percentage field as reported in the logger statistics.
Bug: 22855208
Change-Id: Id9c5e4a907ed0f9319beb9ddbfa27f4844bffc7d
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
- Correct default tense for kernel or user logger
- harden code that parses the benchmark data
- give more meaning to the spam filter test
Change-Id: I97699037ca9d56718f53f08d22be79092fb431de
- if network read/write broken up, reassemble the pieces.
- Use a 20ms poll to check if a new fragment has been
sent by the other side.
- fixup logd-unit-tests to take a (simplified) fragment
from the liblog changes.
Bug: 14164765
Change-Id: I98ff87888c119e1e8349717646d0f733e8971bc8
* Test statistics output, all four main log id types
are checked to be present, and output is properly
formatted with header (ascii new-line terminated
byte count) and trailer (newline formfeed) frames.
* On dev build test dgram_qlen, circumvent if
liblog benchmarks executed first though.
* Test if kernel and user space loggers are
present, and if any content has leaked to both.
* test benchmark and use it to verify worst UID pruning
Change-Id: I890c89f64825956f40108de806ed750b0170ac6c
