Commit Graph

546 Commits

Author SHA1 Message Date
Mark Salyzyn 0f85817985 logd: rename sort() for pids to sortPids()
Bug: 30118730
Change-Id: If992b53b52a7470427fbe82abb93c95c1b2dc57a
2016-07-15 14:37:04 -07:00
Mark Salyzyn 36a8711260 logd: drop prdebug inline
Makes the prdebug helper accessible for debugging

Bug: 30118730
Change-Id: Ieab60fd18221108ae27c54140a25061ab29ca1a3
2016-07-15 14:36:50 -07:00
Mark Salyzyn 35f7799f16 Merge \"logd: trailing spaces in log statistics\"
am: d59d16a49d

Change-Id: I3f9432af451b13e5641d8ab6a8c275516d636439
2016-07-15 19:04:49 +00: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 6fb57f996a Merge \"logcatd: trampoline persist.logd.logpersistd to logd.logpersistd\"
am: 3ba829c75c

Change-Id: Iec3c591d5121be9451597e90b9a6467d7c9a6986
2016-07-13 18:02:23 +00:00
Mark Salyzyn 2591d483c8 logcatd: trampoline persist.logd.logpersistd to logd.logpersistd
Best practices so that device can set logd.logpersistd properties.
Values can be overriden with trampolines for persist.logd.logpersistd
values except as designed for empty content to keep out of the way.

This allows us to set logd.logpersistd* for a non-persistent collection
that does not survive a reboot, and to use persist.logd.logpersistd*
for persistent collection that does survive a reboot.

Added logd.logpersistd.enable to gate when logpersist service can be
run allowing the properties to be adjusted safely prior to this state
as is the case for device property.

NB: /init will complain when trying to trampoline an empty property,
    this is acceptable for functionality, but may be considered
    annoying from the logging perspective.

Bug: 28936216
Bug: 29831823
Change-Id: I97317e8eedfae4daa8e3ef39e64e7c5c23d8b573
2016-07-08 11:06:06 -07:00
Sami Tolvanen 589994504a resolve merge conflicts of a742d10 to nyc-dev-plus-aosp
Change-Id: Icf3257ee8a47f31ba812a5f47899b8022f4eedb7
2016-06-14 15:55:40 -07:00
Sami Tolvanen a742d10277 Revert "logd: enforce policy integrity"
This reverts commit 0bdad0f231.

Bug: 26902605
Change-Id: I6ce8fa7bef63c45821628265c379970eb64963a2
2016-06-14 11:14:51 -07:00
Elliott Hughes 5f4a946c09 Use alignas for alignment.
Change-Id: I427c407a188682a360c74b2bd5a44dd62551ea66
2016-06-06 19:59:45 -07:00
Chih-Hung Hsieh f0f94fe49b Fix misc-macro-parentheses warnings in liblog.
Bug: 28705665
Change-Id: Ib272a83cb93b09d986c19a40e23a2679b9e17558
2016-05-18 15:48:50 -07:00
Chih-Hung Hsieh 1cc82ce95c Fix google-explicit-constructor warnings.
Bug: 28341362
Change-Id: I2cf746fd07addc6e6c22e98e2a5bb8a8ce47c885
2016-04-25 13:49:46 -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 07522c6e9b logd: check return values
(cherry pick from commit bf7d0b8875)

The setgid() and setuid() call failure in logd.daemon thread
do not block overall functionality, so clearly tell static
analyzer and developers that we do not care to check their
return values.

SideEffects: None

Bug: 27434072
Change-Id: I6fdc87e8311ebc0173716080bbd72c86b3f00f78
2016-03-02 11:37:21 -08:00
Mark Salyzyn c348416198 logd: clarify release_Locked() for static analyzer
(cherry pick from commit 0ecdec7a09)

release_Locked() is called with a reference count and threadRunning,
the static analyzer can not tell this and estimates that a call to
delete this will occur. So let us invent a new call
release_nodelete_Locked() to ensure it is clear we will not be
arranging a delete this in the context of this code path. The
delete this will follow in the immediate codepath in this function
after threadRunning is cleared, and decRef_Locked() is called.

Change will also remove any developer FUD regarding release_Locked()
usage at this location.

SideEffects: None

Bug: 27434831
Change-Id: I91b060b2dadc72cc449fa381c934afb577bee037
2016-03-02 11:37:21 -08:00
Mark Salyzyn bf7d0b8875 logd: check return values
The setgid() and setuid() call failure in logd.daemon thread
do not block overall functionality, so clearly tell static
analyzer and developers that we do not care to check their
return values.

SideEffects: None

Bug: 27434072
Change-Id: I6fdc87e8311ebc0173716080bbd72c86b3f00f78
2016-03-02 07:54:45 -08:00
Mark Salyzyn 0ecdec7a09 logd: clarify release_Locked() for static analyzer
release_Locked() is called with a reference count and threadRunning,
the static analyzer can not tell this and estimates that a call to
delete this will occur. So let us invent a new call
release_nodelete_Locked() to ensure it is clear we will not be
arranging a delete this in the context of this code path. The
delete this will follow in the immediate codepath in this function
after threadRunning is cleared, and decRef_Locked() is called.

Change will also remove any developer FUD regarding release_Locked()
usage at this location.

SideEffects: None

Bug: 27434831
Change-Id: I91b060b2dadc72cc449fa381c934afb577bee037
2016-03-02 07:38:34 -08:00
Sami Tolvanen 2060a83775 logd: add a comment about untrusted content in the audit log
A single space character in search terms separates us from a denial of
service attack that forces the device into safe mode.  This CL adds a
comment that hopefully stops the spaces from being accidentally deleted
in future.

Change-Id: I33b2632ef4211fa1688ac9c8f0cf7d0c667766c1
2016-02-29 14:10:59 -08:00
Sami Tolvanen 89e0429ce7 logd: stop log spam when integrity enforcement is suppressed
Bug: 27389331
Change-Id: I9f3bc21eb1b85b9fda4fa0a5c5b4da94e5e7cc1c
(cherry pick from commit abda9340e6)
2016-02-29 13:18:46 -08:00
Sami Tolvanen abda9340e6 logd: stop log spam when integrity enforcement is suppressed
Bug: 27389331
Change-Id: I9f3bc21eb1b85b9fda4fa0a5c5b4da94e5e7cc1c
2016-02-29 12:08:39 -08:00
Nick Kralevich 99fb01e42a Revert "logd: Don't trigger an integrity failure on permissive SELinux denials"
external/sepolicy commit bca98efa575bedab68f2d5eaee2cd1fd1741962b
ensures that no permissive domains can be on user builds, and
external/sepolicy commit 3872ee396898fcb23bdc49c37fd02d81014aaa5f
re-enables enforcing mode on cameraserver.

The conditions which lead to the integrity failure detection
triggering can no longer occur. Revert the patch which relaxed
the detection.

This reverts commit 33ee84f871.

Bug: 27313768
Bug: 26902605
Change-Id: I8ee97d0858345695f9df8240de4e696f4a9ba008
2016-02-27 08:31:57 -08:00
Nick Kralevich 33ee84f871 logd: Don't trigger an integrity failure on permissive SELinux denials
Only trigger an integrity failure if a policy is reloaded or
SELinux is disabled. Don't trigger the integrity failure if
we see a permissive=1 denial, which could occur if an SELinux
domain is in permissive mode.

Bug: 27313768
Bug: 26902605
Change-Id: Ib85a2799eb6378ae8acdb965b1812d691183fdd3
2016-02-26 17:00:15 -08:00
Mark Salyzyn d26b2cacad logd: sock_alloc_send_pskb starves pruning
(cherry pick from commit 5c77ad55d0)

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
2016-02-25 12:43:12 -08:00
Mark Salyzyn 317bfb923c logd: Allow (some) headers to be individually importable
(cherry pick from commit 2ad0bd0a9b)

LogReader.h needs to be individually importable.

Fix a few others, drop includes of local includes, let them be
included in source instead and allow headers to be included
alphabetically. Was not a complete audit since goal was to
separate LogReader.h out from the pack.

Bug: 27242723
Change-Id: Ic7759ef90995e5bd285810706af33550c73cf5b5
2016-02-25 12:42:31 -08:00
Mark Salyzyn 5c77ad55d0 logd: sock_alloc_send_pskb starves pruning
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
2016-02-24 10:15:32 -08:00
Mark Salyzyn 2ad0bd0a9b logd: Allow (some) headers to be individually importable
LogReader.h needs to be individually importable.

Fix a few others, drop includes of local includes, let them be
included in source instead and allow headers to be included
alphabetically. Was not a complete audit since goal was to
separate LogReader.h out from the pack.

Bug: 27242723
Change-Id: Ic7759ef90995e5bd285810706af33550c73cf5b5
2016-02-24 10:15:22 -08:00
Sami Tolvanen 0bdad0f231 logd: enforce policy integrity
If a SELinux policy change or a switch to permissive mode is detected
on a user build, restart the device into safe mode, and keep it there
until an OTA is applied or user data is wiped.

This change deprecates the ro.logd.auditd property.

Needs matching changes from
  I781c3059ea8d4fb2f0c923e4488b1932d69678d3
  Ica825cf2af74f5624cf4091544bd24bb5482dbe7
  Id3ca7889ede30b54b7af73dd50653ca1a20d59aa

Bug: 26902605
Change-Id: Idcdc5bff133f13c1267f0ec0a75cc8cf1ddbda0d
(cherry picked from commit d122ee65b6)
2016-02-22 14:00:43 -08:00
Sami Tolvanen d122ee65b6 logd: enforce policy integrity
If a SELinux policy change or a switch to permissive mode is detected
on a user build, restart the device into safe mode, and keep it there
until an OTA is applied or user data is wiped.

This change deprecates the ro.logd.auditd property.

Needs matching changes from
  I781c3059ea8d4fb2f0c923e4488b1932d69678d3
  Ica825cf2af74f5624cf4091544bd24bb5482dbe7
  Id3ca7889ede30b54b7af73dd50653ca1a20d59aa

Bug: 26902605
Change-Id: Idcdc5bff133f13c1267f0ec0a75cc8cf1ddbda0d
2016-02-16 12:54:54 -08:00
Mark Salyzyn d1f41d606b logd: use ro.debuggable instead of ro.build.type
Change-Id: Ic644f1f78e68094f700834675f4acc63386a6b92
2016-02-10 10:23:03 -08:00
Mark Salyzyn d048f113a3 logd: add internal prdebug function
Usage: android::prdebug(const char *fmt, ...) __printflike(1, 2);

Will add logd prefix tag, log as debug priority in kernel logs,
and will suffix a newline if one is not supplied. To be used to
aid debugging of the logger only.

Change-Id: I217326ef34dc4eb0ea076bacb7a7a8b564c931c3
2016-02-09 07:46:39 -08:00
Mark Salyzyn 0604f6fbae init.rc: too many start logd
Bug: 26934873
Change-Id: Ia00da6253a50bedc8ba825df1cf641b86cdebeed
2016-02-02 16:01:17 -08:00
Mark Salyzyn 8fa8896d2e logd: security buffer only AID_SYSTEM reader
- limit AID_SYSTEM uid or gid to read security buffer messages
- adjust liblog tests to reflect the reality of this adjustment

To fully test all security buffer paths and modes

$ su 0,0,0 /data/nativetest/liblog-unit-tests/liblog-unit-tests --gtest_filter=liblog.__security*
$ su 1000,1000,1000 /data/nativetest/liblog-unit-tests/liblog-unit-tests --gtest_filter=liblog.__security*
$ su 2000,2000,2000 /data/nativetest/liblog-unit-tests/liblog-unit-tests --gtest_filter=liblog.__security*

ToDo: Integrate the above individually into the gTest Q/A testing

Bug: 26029733
Change-Id: Idcf5492db78fa6934ef6fb43f3ef861052675651
2016-02-01 13:29:06 -08:00
Mark Salyzyn c85ce9ba8e Merge "Revert "logd: security buffer only AID_SYSTEM reader"" 2016-01-26 22:38:58 +00:00
Mark Salyzyn 674ce6ef58 Revert "logd: security buffer only AID_SYSTEM reader"
This reverts commit 756332e88b.

Change-Id: Ib8607ac758b7e88a9db716ec4274ec0e4e3dc596
2016-01-26 21:47:35 +00:00
Mark Salyzyn 69ce7c5483 Merge "logd: security buffer only AID_SYSTEM reader" 2016-01-26 20:41:51 +00:00
Mark Salyzyn 756332e88b logd: security buffer only AID_SYSTEM reader
Bug: 26029733
Change-Id: I140e5eb8bb39271fa674744651127e3fc545cbe8
2016-01-26 07:20:29 -08:00
Mark Salyzyn ef4e4f3f07 logd: test wrap functionality
Behavior is modified now, so react by fortifying the tests

Bug: 26447386
Change-Id: I6295783a0bc75282499aeba503a86bdb846908b5
2016-01-21 11:56:23 -08:00
Mark Salyzyn 7fd6c5c6f5 logd: prune maintain per-id watermark (part deux)
iterator corruption as we allow mLast to slip through the FIFO

Bug: 23685592
Bug: 26646087
Change-Id: Ifcbaecf390ee47b195c3d823d080c66c15db4530
2016-01-19 16:14:39 -08:00
Mark Salyzyn 7b7b2da6b8 Merge "logd: prune maintain per-id watermark" 2016-01-13 20:23:28 +00:00
Mark Salyzyn ae6aa1f1ed Merge "logd: wrap timed entry too early, timeout immediately" 2016-01-12 21:57:50 +00:00
Mark Salyzyn 4690640760 logd: unaligned access on security buffer
Bug: 26485626
Change-Id: I990447ca59982bb2de15decda575fd0e2838b5ed
2016-01-12 10:09:31 -08:00
Mark Salyzyn 507eb9fec2 logd: prune maintain per-id watermark
Without this change LogBuffer::prune and LogBuffer::erase
contributes 16.7% and 1.79% respectively. With this change,
they contributes 3.06 and 2.33% respectively. Pruning is
performed roughly 1 in every 255 log entries, a periodic
tamer latency spike.

Bug: 23685592
Change-Id: I6ae1cf9f3559bca4cf448efe8bcb2b96a1914c54
2016-01-11 14:46:51 -08:00
Mark Salyzyn 0157097845 logd: wrap timed entry too early, timeout immediately
Bug: 26447386
Change-Id: I8d5588831f558061ef21b2a5aeedc865e9ae4cc7
2016-01-07 15:13:14 -08:00
Mark Salyzyn 1a5bac2069 Merge "Revert "logd: liblog: whitelist "snet_event_log""" 2016-01-06 21:22:04 +00:00
Mark Salyzyn 0ee8de3c2d Revert "logd: liblog: whitelist "snet_event_log""
Callers will not guarantee that they can or will ratelimit, we need to
retain the ability to blacklist snet_event_log as a result.

This reverts commit 6aa21b225d.

Bug: 26178938
Change-Id: Ibf47d2e23a84c56f5f72d02312c698df7ff2b601
2016-01-06 21:19:23 +00:00
Mark Salyzyn 66607ebc0e logd: document ro.logd.size
Bad comment advise in LogBuffer.cpp results in partners failing to
considering using ro.logd.size to set the platform buffer size
default.

NB: It is not good practice to increase the log buffer size to deal
with logspam, as increases will result in logd scale issues getting
closer to hitting the background cgroup cpu cap. Once we hit that
cap, logd spirals, pruning old entries slower than the incoming log
entries. logd.writer will take 100% cpu.

Change-Id: If4a7a74f300d078eeaed0ffd3eb3fd77d1f9fe90
2016-01-05 09:09:18 -08:00
Mark Salyzyn ff8b8e838b logd: build breakage aosp-brillo-master @ 2508494
Change-Id: I38e506bc997c6e9759a064b517f9372a27d0e510
2015-12-30 13:46:07 -08:00
Mark Salyzyn 554630f94e Merge "logd: isMonotonic improvements" 2015-12-30 21:31:58 +00:00
Mark Salyzyn 6aa21b225d logd: liblog: whitelist "snet_event_log"
Dangerous bridge to cross to whitelist, who is special, who is not?
Rationalized as these events are used to catch exploits on platform.
As it stands no one should be allowed to block any messages in the
security context, not even for development purposes.

Bug: 26178938
Change-Id: Ibdc76bc0fe29ba05be168b623af1c9f41d7edbd2
2015-12-30 10:07:19 -08:00
Mark Salyzyn 10b82b6834 logd: isMonotonic improvements
Use 1972 as a right delineation. Otherwise use half way point
between the monotonic and realtime. Treat correction factor as
unsigned, ensure that any wrapping to a negative value is
dropped or set to EPOCH. Acknowledge that we can get a more
accurate time track by acquiring the time rather than relying on
healthd timestamp.

Bug: 26331432
Change-Id: I09075fca58676a30cf7d87baf2d4b0f53795abaa
2015-12-29 11:34:29 -08: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 9c66a58f21 logd: Allow flags "eng" and "svelte" in boolean
- enhance property_get_bool, drop property_get_bool_svelte
- enhance base properties with ro and persist variants
- update and fortify README.property
- primarily move auditd and kernel logger into a realm where
  they can be controlled by build properties.
- Move logd.klogd to logd.kernel, and add ro.logd.kernel
  and persist.logd.kernel.
- Add ro.logd.auditd and persist.logd.auditd.
- Document persist.logd.security
- Document log.tag and persist.logd.tag properties.
- Document ro.logd.size, persist.logd.size and logd.size
  properties.

Bug: 26178938
Bug: 26029733
Bug: 17760225
Change-Id: Ibc1a497e45d69db5cf52133937f7ba6fb1d6cd21
2015-12-22 07:44:31 -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 7b4a2049b0 logd: test drop __unused
Change-Id: I1ccf49809b8a0a125601bdb52834c463e2d94165
2015-12-18 10:35:00 -08:00
Mark Salyzyn 236fecd923 Merge "logd: ro.config.low_ram set buffer size to 64K" 2015-12-17 23:47:14 +00:00
Mark Salyzyn 1d9c7e728f logd: simpleperf inspired optimizations
memset is hot on log writes with too much overhead, not required.

Bug: 24444530
Bug: 23685592
Change-Id: Ibe3c83abca6774fc79a3be461f2f1585f4a9b1ff
2015-12-15 14:24:04 -08:00
Mark Salyzyn cdda62b2c1 logd: ro.config.low_ram set buffer size to 64K
Bug: 25792367
Change-Id: Icae85a7de70b3a71f89b2bf8c80866649f727177
2015-12-14 14:37:07 -08:00
Mark Salyzyn 86052a5d4f Merge "logd: liblog: logcat: Add LOG_ID_SECURITY" 2015-12-11 17:33:33 +00:00
Mark Salyzyn 30edbdce9b Merge changes I598c8c5c,I672b0f4d,Id882978b,Idff5e080,Ib124eca1, ...
* changes:
  logger.h: reduce maximum payload so sum is page size
  liblog: test for maximum payload can not survive change
  liblog: logprint use uid name if length less then 5
  liblog: logprint add uid format modifier
  liblog: readlog apps get logger_entry_v4 for pstore
  logd: readlog apps get logger_entry_v4
  logger.h: Add definition for logger_entry_v4
2015-12-11 16:42:28 +00:00
Mark Salyzyn ad9dac1c27 Merge "logd: best 2/3 filter for timezone glitches" 2015-12-10 23:38:03 +00:00
Mark Salyzyn b06247d9a0 logd: best 2/3 filter for timezone glitches
klogd is sensitive to changes in timezone resulting in glitches
surrounding conversion to local realtime logging. logger manages
a map from monotonic to realtime, but the process is racey since
the system can change the timezone at any time, this catches those
cases where it glitches.

Bug: 21868540
Change-Id: I03de6675fcd04f18ba7306a24dc3d9e750d86976
2015-12-10 13:20:48 -08:00
Mark Salyzyn f011a335f2 logd: logd-reinit exits with 194
Bug: 26115803
Change-Id: I6e8843ce9766756a40e6d176e0a822f62045c2af
2015-12-10 12:26:08 -08:00
Mark Salyzyn 7b87365ecf logd: readlog apps get logger_entry_v4
Adds the uid field to outgoing content for readlog applications.
AID_LOG, AID_ROOT and AID_SYSTEM gain access to the information.

Bug: 25996918
Change-Id: I0254303c19d174cbf5e722c38844be5c54410c85
2015-12-09 08:12:07 -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 fc9f5b8af4 logd: test wakeup on wrap timeout
Change-Id: I8dd605452f1fef7706a627eedc251e39bb2e34cc
2015-12-07 14:24:02 -08:00
Mark Salyzyn b75cce0389 logd: wakeup on wrap or timeout
If a timeout is specified for the reader, then go to sleep
with the socket open. If the start time is about to get
pruned in the specified log buffers, then wakeup and dump
the logs; or wakeup on timeout, whichever comes first.

Bug: 25929746
Change-Id: I7d2421c2c5083b33747b84f74d9a560d3ba645df
2015-12-07 14:24:02 -08:00
Mark Salyzyn 3ea02e8eca Merge "logd: test: leniency towards background cgroup" 2015-12-07 20:59:34 +00:00
Mark Salyzyn 2e2d2edc59 Merge "logd: test: statistics report chatty effective percentage" 2015-12-07 19:30:51 +00:00
Mark Salyzyn 074f542476 logd: test: leniency towards background cgroup
Accepting a new lower standard of performance due to
the realities of the background cgroup.

Change-Id: Icd85050ffbf7f0129dd4c053323faedd0ff74048
2015-12-07 11:26:12 -08:00
Mark Salyzyn f33657da4d logd: test: statistics report chatty effective percentage
Add parsing to recognize optional chatty effective
percentage field as reported in the logger statistics.

Bug: 22855208
Change-Id: Id9c5e4a907ed0f9319beb9ddbfa27f4844bffc7d
2015-12-07 11:10:04 -08:00
Mark Salyzyn ba7a9a016b logd: liblog: logcat: switch to android_log_clockid() (2)
android_log_timestamp returns the property leading letter,
it is better to return a clockid_t with android_log_clockid()

Bug: 23668800
Change-Id: I38dee773bf3844177826b03a26b03215c79a5359
2015-12-07 18:45:31 +00:00
Mark Salyzyn b566435b02 Merge "Revert "logd: liblog: logcat: switch to android_log_clockid()"" 2015-12-07 18:31:44 +00:00
Mark Salyzyn 9e18cdcebd Revert "logd: liblog: logcat: switch to android_log_clockid()"
This reverts commit 77b5696b1d.

Change-Id: I7711bf1a7e3f72ed29a2498d7287b725a0e624bd
2015-12-07 18:30:58 +00:00
Mark Salyzyn 9eca0e775b Merge "logd: liblog: logcat: switch to android_log_clockid()" 2015-12-07 18:16:29 +00:00
Elliott Hughes 4f71319df0 Track rename of base/ to android-base/.
Change-Id: Idf9444fece4aa89c93e15640de59a91f6e758ccf
2015-12-04 22:00:26 -08:00
Mark Salyzyn 77b5696b1d logd: liblog: logcat: switch to android_log_clockid()
android_log_timestamp returns the property leading letter,
it is better to return a clockid_t with android_log_clockid()

Bug: 23668800
Change-Id: I3c4e3e6b87f6676950797f1f0e203b44c542ed43
2015-12-04 14:49:19 -08:00
Mark Salyzyn e6cf1c6372 Merge "Revert "liblog: resolve deadlocks"" 2015-11-16 19:07:47 +00:00
Mark Salyzyn c2e7d4965f Revert "liblog: resolve deadlocks"
This reverts commit 7a2a307192.

Bug: 25693940
Change-Id: I9a7c926289e972f80c03c92e33535e1dedaa7381
2015-11-16 19:00:41 +00:00
Mark Salyzyn eb29808615 logd: klogd: parse error
Resolve three areas missing taglen checking. Add some additional
limit-checking paranoia. Problem started when p was allowed to
go beyond the size of the incoming buffer in some blind
p = cp + 1 fragments, placed the check for that after them all
before harm could be done, rather than in each location.

Bug: 25620123
Change-Id: Ib5687fd30ef0cd3ba3bc0df310b436ad675ccabc
2015-11-13 07:58:05 -08:00
Mark Salyzyn 7a2a307192 liblog: resolve deadlocks
Although ever present, an increased regression introduced with
commit b6bee33182 (liblog: logd:
support logd.timestamp = monotonic).

A signal handler can interrupt in locked context, if log is written
in the signal handler, we are in deadlock. Block signals while we
are locked. Separate out timestamp lock from is loggable lock to
reduce contention situations. Provide a best-guess response if
lock would fail in timestamp path.

Bug: 25563384
Change-Id: I6dccd6b99ebace1c473c03a785a35c63ed5c6a8a
2015-11-12 15:39:04 -08:00
Nick Kralevich c39ba5ae32 Enable hidepid=2 on /proc
Add the following mount options to the /proc filesystem:

  hidepid=2,gid=3009

This change blocks /proc access unless you're in group 3009
(aka AID_READPROC).

Please see
  https://github.com/torvalds/linux/blob/master/Documentation/filesystems/proc.txt
for documentation on the hidepid option.

hidepid=2 is preferred over hidepid=1 since it leaks less information
and doesn't generate SELinux ptrace denials when trying to access
/proc without being in the proper group.

Add AID_READPROC to processes which need to access /proc entries for
other UIDs.

Bug: 23310674
Change-Id: I22bb55ff7b80ff722945e224845215196f09dafa
2015-11-09 09:08:46 -08:00
Mark Salyzyn 8897a3fffd Merge "liblog: logd: support logd.timestamp = monotonic" 2015-11-04 00:31:53 +00:00
Mark Salyzyn 50122695d2 logd: pruning time horizon
Estimate a time horizon of ten fold for worst UID pruning

Bug: 24782000
Change-Id: I7118deb6d42531c68ed2ac2a59c57b0580b942cc
2015-11-03 15:34:15 -08:00
Mark Salyzyn b6bee33182 liblog: logd: support logd.timestamp = monotonic
if ro.logd.timestamp or persist.logd.timestamp are set to the value
monotonic then liblog writer, liblog printing and logd all switch to
recording/printing monotonic time rather than realtime. If reinit
detects a change for presist.logd.timestamp, correct the older entry
timestamps in place.

ToDo: A corner case condition where new log entries in monotonic time
      occur before logd reinit detects persist.logd.timestamp, there
      will be a few out-of-order entries, but with accurate
      timestamps. This problem does not happen for ro.logd.timestamp
      as it is set before logd starts.

NB: This offers a nano second time accuracy on all log entries
    that may be more suitable for merging with other system
    activities, such as systrace, that also use monotonic time. This
    feature is for debugging.

Bug: 23668800
Change-Id: Iee6dab7140061b1a6627254921411f61b01aa5c2
2015-11-03 15:15:51 -08:00
Mark Salyzyn 14105639a9 Merge "logd: statistics report chatty effective percentage"
am: d2c8cf8265

* commit 'd2c8cf826587de9ef1269ba22fd70df00f874c23':
  logd: statistics report chatty effective percentage
2015-10-30 22:02:15 +00:00
Mark Salyzyn 2c0f84da2e Merge "logd: Add support for *.logd.filter"
am: 95ec339f5e

* commit '95ec339f5ef68696630df470e172bbb306faa1b6':
  logd: Add support for *.logd.filter
2015-10-30 22:02:10 +00: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 932f7acc81 logd: Add support for *.logd.filter
- Add device (ro.logd.filter), persistent (persist.logd.filter)
  properties to control the default filters
- Allow logcat -P default to produce expected results
- Allow logcat -P disable to produce expected results

Change-Id: I651cb705373ec1e88a99e4b9086da4f9668a468a
2015-10-30 14:54:17 -07:00
Andreas Gampe 31e78998b0 Merge "Logd: Fix missing include of rc file"
am: 054c099f1b

* commit '054c099f1bbc814e7b20cc20c3ba369161e130e7':
  Logd: Fix missing include of rc file
2015-10-23 04:15:51 +00:00
Andreas Gampe f5852ce11b Logd: Fix missing include of rc file
This went missing in commit aeca97ba1c.

Change-Id: I9d7e48a2ffb1649f3fa515a9d12d5fbdd2ed58b7
2015-10-22 20:36:53 -07:00
Daniel Cashman 2d78403633 Merge "logd: use libpackageparser"
am: 89065609c9

* commit '89065609c904c8ffdf0fdaec13ede2989ceb110e':
  logd: use libpackageparser
2015-10-22 23:12:10 +00:00
William Roberts aeca97ba1c logd: use libpackageparser
Switch from the internal packages.list file parser
implementation to a common parser library.

Change-Id: I87a406802f95d8e7bfd8ee85f723f80e9e6b6c0c
Signed-off-by: William Roberts <william.c.roberts@intel.com>
2015-10-14 20:22:44 -07:00
Mark Salyzyn ff5ef45e29 am cee44732: Merge "logd: correct for number of elements in prune"
* commit 'cee44732e61c3e0f9491aa6cea78670ed6c9c89d':
  logd: correct for number of elements in prune
2015-10-13 22:25:43 +00: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 904864554e am 9b3a2784: Merge "logd: use coalesce instead of merge (cleanup)"
* commit '9b3a2784b94d88492906384ab3f3c9863f6b5eea':
  logd: use coalesce instead of merge (cleanup)
2015-10-13 16:52:02 +00:00
Mark Salyzyn 9b3a2784b9 Merge "logd: use coalesce instead of merge (cleanup)" 2015-10-13 16:47:15 +00:00
Mark Salyzyn 7c009ac097 am 1c04253a: Merge "logd: object layer format statistics"
* commit '1c04253af2077de0250e4082cadd4f9bfffc4ea2':
  logd: object layer format statistics
2015-10-12 22:14:26 +00:00
Mark Salyzyn 1c04253af2 Merge "logd: object layer format statistics" 2015-10-12 22:10:30 +00:00
Mark Salyzyn aaad42f47c logd: use coalesce instead of merge (cleanup)
- switch to coalesce instead of merge in naming of functions
  and variables. Confusing since we also to merge-sorts and
  other activities in the logger.
- define maxPrune rather than using a number in the code path.

Bug: 24511000
2015-10-09 15:00:44 -07:00
Bill Yi 27bdd9a71c Merge commit '2b88845e4d7ae862d9735eec3c03d633d4f1d58d' into HEAD 2015-10-08 10:37:51 -07:00
Mark Salyzyn 2b25c66070 logd: clearAll by UID speedup
- If doing a clear, skip accounting
- Ensure for busy checking, behind a region lock for instance, only
  break out if there was something to do. Basically move the filter
  actions first, and defer checking the region lock to the ends of
  the loops.

Bug: 23711431
Change-Id: Icc984f406880633516fb17dda84188a30d092e01
2015-10-07 16:24:57 -07:00
Mark Salyzyn c5dc970edc logd: clear return and deal with busy if readers locked
- Propagate to caller the clearing errors, busy blocked by reader.
- For clear, perform retries within logd with a one second lul each,
  telling readers to skip, but on final retry to kill all readers if
  problem still persists due to block reader (or high volume logspammer).

Bug: 23711431
Change-Id: Ie4c46bc9480a7f49b96a81fae25a95c603270c33
2015-10-07 16:23:57 -07:00
Mark Salyzyn de4bb9c1a7 logd: update region lock after entry has passed to reader socket
- The reader region level indicates the location to protect, but once
  it has been passed to the calling reader, then allow us to go
  one beyond so that a clear or prune thread can remove the entry.

Bug: 23711431
Change-Id: I0f2389858dd8c83366c034360f67d7c363625b56
2015-10-07 16:23:57 -07:00
Mark Salyzyn 86eb38f3ca logd: clientHasLogCredentials false negatives
Vote three times in /proc/pid/status to look for AID_LOG group

If not, we may default to the callers UID, and the net result is
to perform the task related to that UID. For adb logcat and
shell logcat, the UID is AID_SHELL which typically has no logs,
leaving no net action taken.

Bug: 23711431
Change-Id: I2b5900a2d37173bd995eb308ee9ecafa20602b62
2015-10-07 16:08:28 -07:00
Mark Salyzyn 1c3009c644 am 2b5f97cc: am 88e01661: Merge "logd: optimize code hotspots"
* commit '2b5f97cc0d3ecddcebee0e1ddc79bd7f994dc2b3':
  logd: optimize code hotspots
2015-10-05 16:31:07 +00:00
Mark Salyzyn b6a1e85004 am be162cf2: am 72146b93: Merge "logd: Add LogUtils.h"
* commit 'be162cf236fb790973a05874919cc01f25434481':
  logd: Add LogUtils.h
2015-10-05 16:31:05 +00: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 2b5f97cc0d am 88e01661: Merge "logd: optimize code hotspots"
* commit '88e0166123eca72cbfc28e92d8abaa95b9b9ce0e':
  logd: optimize code hotspots
2015-10-05 16:25:54 +00:00
Mark Salyzyn be162cf236 am 72146b93: Merge "logd: Add LogUtils.h"
* commit '72146b931ca61e942df91407b561f22648a70bf2':
  logd: Add LogUtils.h
2015-10-05 16:25:53 +00: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 5ac5c6b193 logd: Add LogUtils.h
Move prototypes from LogBufferElement.h to LogUtils.h

Change-Id: I55e42e17e6c997e35b2b78b87fd2f84f8f393282
2015-10-02 16:36:41 -07:00
Mark Salyzyn 7765a98a90 am 900362c3: am 1b2fb587: Merge changes I42162365,Ia72f1305,I57d1f86c,I026d074e
* commit '900362c36eb531c88d37d8fa57b66c45ed165122':
  logd: klogd deal with nuls in dmesg
  logd: log_strtok_r deal with nuls
  liblog: logprint: printable nul
  logd: klogd: sniff for time correction on Mediatek
2015-09-30 20:11:41 +00:00
Mark Salyzyn 900362c36e am 1b2fb587: Merge changes I42162365,Ia72f1305,I57d1f86c,I026d074e
* commit '1b2fb587eb7db6f9de1dda8663b33d87a2f5a27e':
  logd: klogd deal with nuls in dmesg
  logd: log_strtok_r deal with nuls
  liblog: logprint: printable nul
  logd: klogd: sniff for time correction on Mediatek
2015-09-30 20:04:53 +00:00
Mark Salyzyn 78e4de5899 am db364d25: am 8ec2d8fe: Merge "logd: klogd and Mediatek part deux"
* commit 'db364d251fd72b9689e7573811f6108d9205a4ff':
  logd: klogd and Mediatek part deux
2015-09-30 00:11:21 +00:00
Mark Salyzyn db364d251f am 8ec2d8fe: Merge "logd: klogd and Mediatek part deux"
* commit '8ec2d8fec6d099d44151b1e29366002e569d3c2a':
  logd: klogd and Mediatek part deux
2015-09-30 00:05:41 +00:00
Mark Salyzyn 151beac76d logd: klogd deal with nuls in dmesg
Switch to using string and length in all transactions, treating
trailing nuls the same as spaces.

ToDo: change dumpstate (bugreport) to use logcat -b printable _regardless_

Bug: 23517551
Change-Id: I42162365e6bf8ed79d356e7b689a673902116fdb
2015-09-29 15:51:38 -07:00
Mark Salyzyn ea1a241107 logd: log_strtok_r deal with nuls
Rename to log_strntok_r and change from dealing with strings
to dealing with a string and an associated length.

Bug: 23517551
Change-Id: Ia72f1305a53f55eeef9861ac378fb8205fd2378e
2015-09-29 15:43:34 -07:00
Mark Salyzyn 2d159bf3b5 logd: klogd: sniff for time correction on Mediatek
Need some more flexibility when parsing kernel messages
cluttered with extra fluff. This is the minimal relaxation
we can do to the rules to ensure that we work on all
possible devices and kernels when sniffing for time
correction information.

We want to minimize any future maintenance, keep in mind
klogd is a "userdebug" or "eng" feature and is disabled
in "user" builds. Manage expectations.

Bug: 23517551
Change-Id: I026d074e14fb2550e728683e85a973bd87e78a9c
2015-09-29 15:43:07 -07:00
Mark Salyzyn 47dba71f24 logd: klogd and Mediatek part deux
- switch to an open coded strnrchr
- validity checking on n, taglen and b values.

Bug: 23517551
Change-Id: I568e25c5aa6d8474835454a0e83b19c2921b7986
2015-09-29 15:40:08 -07:00
Mark Salyzyn 936d65f59b am cb2ab20d: am 87122ce1: Merge "logd: increase dgram_max_qlen to 600"
* commit 'cb2ab20d480cdf488e5b5bf37dc55ca7f0ddee67':
  logd: increase dgram_max_qlen to 600
2015-09-28 15:54:05 +00:00
Mark Salyzyn cb2ab20d48 am 87122ce1: Merge "logd: increase dgram_max_qlen to 600"
* commit '87122ce1d60dd6fbc18e747d976db734d502f2bf':
  logd: increase dgram_max_qlen to 600
2015-09-28 15:50:02 +00:00
Mark Salyzyn 39944c89a9 logd: increase dgram_max_qlen to 600
Seeing liblog messages on system_server runtime restart
(too much system_server spam, 566 messages in 72ms)

Bug: 23788621
Change-Id: I5171f2c19a3538da190fc6c2b40e978d89bf0e20
2015-09-25 14:15:53 +00:00
Mark Salyzyn 44a34e4525 am 96f1b63a: am 44210dfe: Merge "logpersist: bundle with logcatd service"
* commit '96f1b63a916a86774780bc9e15ac857ac3dd6fde':
  logpersist: bundle with logcatd service
2015-09-21 22:31:59 +00:00
Mark Salyzyn 529c2c1c07 am 9c92ad31: am 2f25cb47: Merge "logpersist: Additional barrier"
* commit '9c92ad3125b251109c6537e45d147650756058ca':
  logpersist: Additional barrier
2015-09-21 22:31:57 +00:00
Mark Salyzyn 96f1b63a91 am 44210dfe: Merge "logpersist: bundle with logcatd service"
* commit '44210dfe4bec1d62e6bed85b7df2afe020b9190d':
  logpersist: bundle with logcatd service
2015-09-21 22:22:26 +00:00
Mark Salyzyn 9c92ad3125 am 2f25cb47: Merge "logpersist: Additional barrier"
* commit '2f25cb479bea6bf7797a33b06359f71c58b38347':
  logpersist: Additional barrier
2015-09-21 22:22:24 +00:00
Tom Cherry 984bd8323d resolved conflicts for 5caca3dd to mnc-dr-dev-plus-aosp
Change-Id: I773e514a8232b77cdd566dc36c9efc4e15f206f0
2015-09-21 14:25:34 -07:00
Mark Salyzyn 8c943b6dc8 logpersist: bundle with logcatd service
Bug: 23186545
Change-Id: I130d7c7e120acb372e58aec028f39e161d53628e
2015-09-21 13:53:01 -07:00
Mark Salyzyn 1b9456a1a5 logpersist: Additional barrier
If this shows up on "user" builds, block execution

Change-Id: I2e137d1ff7583ac000b81dee7390b582dfd02095
2015-09-21 13:52:45 -07:00
Mark Salyzyn 93807d472d Merge "logd: worst uid record watermark part five" into mnc-dr-dev 2015-09-14 14:16:49 +00:00
Mark Salyzyn 805ef688af logd: klogd and Mediatek
(cherry pick from commit 46d159d462)

- sniff for PID in kernel log messages if available
- properly deal with klogd watermark in face of modified output
- deal more stringently with priority tag, must have [ following
- suppress process-name stutter in tag that can happen
- do not use : to demark tag if within [ ]

Mediatek-special change that adds <printk_state>(<cpu>)[<pid>:<comm>]
as a prefix to the printk messages. Along the lines of (simplified
for entertainment purposes, YMMV):

    char tbuf[50]; /* printk prefix */
    int this_cpu = smp_processor_id();
    char state = __raw_get_cpu_var(printk_state);
    unsigned tlen = snprintf(tbuf, sizeof(tbuf), "%c(%x)[%d:%s]",
               state, this_cpu, current->pid, current->comm);

Bug: 23517551
Change-Id: I568e25c5aa6d8474835454a0e83b19c2921b7985
2015-09-11 14:51:41 +00:00
Mark Salyzyn 04827ab02a logd: worst uid record watermark part five
(cherry pick from commit 5bb2972dce)

A regression that resulted in increased memory consumption for some
logging patterns because we rarely did merge or leading checks, and
age-out checking. On the last prune cycle, we reset for a full scan.

Add some comments describing the pruning processes.

Bug: 23327476
Bug: 23681639
Bug: 23685592
Change-Id: I22b0f339c9269b006831fda9cefe295a263ebb92
2015-09-10 09:38:07 -07:00
Mark Salyzyn e66f84d7e6 am 784a69f8: Merge "logd: worst uid record watermark part five"
* commit '784a69f8650068980bcc692584b515ab2372ab5b':
  logd: worst uid record watermark part five
2015-09-10 16:30:36 +00:00
Mark Salyzyn 5bb2972dce logd: worst uid record watermark part five
A regression that resulted in increased memory consumption for some
logging patterns because we rarely did merge or leading checks, and
age-out checking. On the last prune cycle, we reset for a full scan.

Add some comments describing the pruning processes.

Bug: 23327476
Bug: 23681639
Bug: 23685592
Change-Id: I22b0f339c9269b006831fda9cefe295a263ebb92
2015-09-10 08:43:03 -07:00
Mark Salyzyn 4ee37bc91e logd: worst uid record watermark part four
(cherry pick from commit 831aa29730)

With part deux we caused an apparent regression by not checking for
stale recorded iterators. This checking was on-purpose bypassesed
when leading prune entries were to be deleted without touching the
statistics engine due to an in-place merge.

Part deux had us leaving iterators we were not focussed on untouched
which in turn because they were left behind, had a much higher
likelihood of being deleted without touching the statistics engine.

Perform the check every delete.

Bug: 23789348
Bug: 23490267
Change-Id: Idc6cc23d1f9e3b6cd9a083139a0de59479fbfe08
2015-09-04 14:32:46 +00:00
Mark Salyzyn 7901658787 am 0df400ec: Merge "logd: worst uid record watermark part four"
* commit '0df400ec117f5b97673bafa25545c3294c3af636':
  logd: worst uid record watermark part four
2015-09-04 14:21:33 +00:00
Mark Salyzyn 831aa29730 logd: worst uid record watermark part four
With part deux we caused an apparent regression by not checking for
stale recorded iterators. This checking was on-purpose bypassesed
when leading prune entries were to be deleted without touching the
statistics engine due to an in-place merge.

Part deux had us leaving iterators we were not focussed on untouched
which in turn because they were left behind, had a much higher
likelihood of being deleted without touching the statistics engine.

Perform the check every delete.

Bug: 23789348
Change-Id: Idc6cc23d1f9e3b6cd9a083139a0de59479fbfe08
2015-09-03 17:13:45 -07:00
Mark Salyzyn 3f5c5a1e69 Merge "logd: worst uid record watermark part three" into mnc-dr-dev 2015-09-01 20:11:11 +00:00
Mark Salyzyn bd44f59f5b Merge "logd: worst uid record watermark part deux" into mnc-dr-dev 2015-09-01 20:11:00 +00:00
Mark Salyzyn 48d88c4b69 am 6bb48f07: Merge "logd: worst uid record watermark part three"
* commit '6bb48f07db448756970266c94b6c7185557ba5a5':
  logd: worst uid record watermark part three
2015-09-01 16:37:25 +00:00
Mark Salyzyn ae26b4d948 logd: worst uid record watermark part three
(cherry pick from commit ccfe8446a1)

Regression that cause records to be preserved for more than a day.

Bug: 23681639
Bug: 23685592
Change-Id: I5e4393c8e3ed935790994c77ec51dc6512a6daa6
2015-08-31 13:56:37 -07:00
Mark Salyzyn aa58a86275 logd: worst uid record watermark part deux
(cherry pick from commit 49afe0d00f)

Only record watermark if not known, or represents the worst UID
currently under focus. This has resulted in a halving of the average
prune time in the face of heavy spam because we get less processing
spikes.

Bug: 23327476
Bug: 23681639
Bug: 23685592
Change-Id: I19f297042b9fc2c98d902695c1c36df1bf5cd6f6
2015-08-31 13:55:54 -07:00
Mark Salyzyn ccfe8446a1 logd: worst uid record watermark part three
Regression that cause records to be preserved for more than a day.

Bug: 23681639
Bug: 23685592
Change-Id: I5e4393c8e3ed935790994c77ec51dc6512a6daa6
2015-08-31 20:51:42 +00:00
Mark Salyzyn bc193c53ec healthd: logd: add timestamp to kernel logged battery messages
(cherry pick from commit acb1ddf56c)

Aid monotonic to realtime logging synchronization correction in
the Android ecosystem by providing a periodic notification.  We
now have the following messages in the kernel logs:

- PM: suspend entry %Y-%m-%d %H:%M:%S.%09q UTC
- PM: suspend exit %Y-%m-%d %H:%M:%S.%09q UTC
- Suspended for %s.%03q seconds
- healthd: battery l=100 ... %Y-%m-%d %H:%M:%S.%09q UTC

Alter klogd to resynchronize on healthd messages as well.

NB: Time using strftime format, %q is a reference to fractional
second as introduced into log_time strptime method.

Bug: 21868540
Change-Id: I854afc0a07dff9c7f26d2b2f68990e52bf90e300
2015-08-27 10:14:10 -07:00
Mark Salyzyn cb19b08dac logd: refine is_prio
(cherry pick from commit 618d0dec50)

- Heuristics associated with translation of kernel messages to
  Android user space logs.
- Limit is_prio to 4 characters, we got false positives on hex
  values like <register contents> with no alpha chars.
- x11 and other register definitions are not valid tags, en0 is
- fix some Android coding standard issues

Change-Id: Idc3dcc53a2cb75ac38628c8ef7a5d5b53f12587a
2015-08-27 10:12:49 -07:00
Mark Salyzyn 928c6124ee am 96ac40af: Merge "logd: klogd and Mediatek"
* commit '96ac40afbf9671e3feaaeb09735fcbb65b0ef733':
  logd: klogd and Mediatek
2015-08-27 14:23:18 +00:00
Mark Salyzyn 46d159d462 logd: klogd and Mediatek
- sniff for PID in kernel log messages if available
- properly deal with klogd watermark in face of modified output
- deal more stringently with priority tag, must have [ following
- suppress process-name stutter in tag that can happen
- do not use : to demark tag if within [ ]

Mediatek-special change that adds <printk_state>(<cpu>)[<pid>:<comm>]
as a prefix to the printk messages. Along the lines of (simplified
for entertainment purposes, YMMV):

    char tbuf[50]; /* printk prefix */
    int this_cpu = smp_processor_id();
    char state = __raw_get_cpu_var(printk_state);
    unsigned tlen = snprintf(tbuf, sizeof(tbuf), "%c(%x)[%d:%s]",
               state, this_cpu, current->pid, current->comm);

Bug: 23517551
Change-Id: I568e25c5aa6d8474835454a0e83b19c2921b7985
2015-08-26 14:57:16 -07:00
Mark Salyzyn 86c8be0443 am 0c3177c5: am 64393789: Merge "logd: worst uid record watermark part deux"
* commit '0c3177c5b13b0826068f922f26f9b1eacbc0fac0':
  logd: worst uid record watermark part deux
2015-08-26 18:02:40 +00:00
Mark Salyzyn 49afe0d00f logd: worst uid record watermark part deux
Only record watermark if not known, or represents the worst UID
currently under focus. This has resulted in a halving of the average
prune time in the face of heavy spam because we get less processing
spikes.

Bug: 23327476
Change-Id: I19f297042b9fc2c98d902695c1c36df1bf5cd6f6
2015-08-24 14:04:45 -07:00
Tom Cherry d2a600eb35 update bundled rc files to their contents from rootdir/init.rc
Bug 23186545

Change-Id: Ieb03ba89db2dee0365ae346295207ddfd29bd2b7
(cherry picked from commit 297991b324)
2015-08-21 21:54:42 +00:00
Tom Cherry 60eb73ed6a am 54b22ca2: am ff5be396: Merge changes from topic \'init-rc-breakup\'
* commit '54b22ca2488e4901265c99a42b5c5e0725a99199':
  init: Queue Triggers instead of Actions
  bundle init.rc contents with its service
2015-08-21 18:20:22 +00:00
Mark Salyzyn 1695b8464d am e7b45195: am 8a4beeb6: Merge "logd: switch asprintf to std::string"
* commit 'e7b451950acc0b845f1fab20a9e62c80bc81750a':
  logd: switch asprintf to std::string
2015-08-21 18:19:49 +00:00
Mark Salyzyn d52484c7aa am 38e2877d: am 67f3dd9c: Merge "logd: statistics switch to std::string"
* commit '38e2877df102c4a817c6b24337a6be253945ed33':
  logd: statistics switch to std::string
2015-08-21 18:19:46 +00:00
Mark Salyzyn 36a590ab36 am aa051ac6: am cf5bd8ba: Merge "logd: white and black switch to std::string"
* commit 'aa051ac68d769194751624612bf68cb753d94b6d':
  logd: white and black switch to std::string
2015-08-21 18:19:43 +00:00
Tom Cherry ff5be396d7 Merge changes from topic 'init-rc-breakup'
* changes:
  init: Queue Triggers instead of Actions
  bundle init.rc contents with its service
2015-08-21 17:42:29 +00:00
Tom Cherry 20391b1de5 bundle init.rc contents with its service
Bug: 23186545
Change-Id: I52616b8ab1165fdef716f9b8f958665f2308c12e
2015-08-21 10:14:43 -07:00
Mark Salyzyn 982bbea061 am 2a04ec35: am 07ee12aa: Merge "logd: worst uid record watermark"
* commit '2a04ec3546a7f1d82b927dd2f49fe46f13f5fe2c':
  logd: worst uid record watermark
2015-08-20 19:32:37 +00:00
Mark Salyzyn 76cbf5f37f am 44a7da74: am 2c1b8f9e: Merge changes Ib0530b9d,I981d9fa6,Icc60dd06,I902ba6b4
* commit '44a7da74bd841eee680870433c1baf82325fb51e':
  logd: log buffer switch to std::list
  logd: white and black switch to std::list
  logd: logtimes switch to std::list
  logd: prune 10% or 256 entries max
2015-08-20 19:32:33 +00:00
Mark Salyzyn 0c5ab13a72 logd: worst uid record watermark
(cherry pick from commit c892ea3fa8)

Hold on to last worst uid watermark and bypass a spike to O(n*n*x)
(n=samples, x=number of spammers) wrt chatty trimming.

Bug: 23327476
Change-Id: I9f21ce95e969b67e576417a760f75c4d86acf364
2015-08-20 11:33:57 -07:00
Mark Salyzyn c2f7eee26b logd: log buffer switch to std::list
(cherry pick from commit 94a89c42fe)

Bug: 23350706
Bug: 23327476
Change-Id: Ib0530b9dd5842c6d05c84d7a66f2531c97461067
2015-08-20 11:32:25 -07:00
Mark Salyzyn dc1c936139 logd: white and black switch to std::list
(cherry pick from commit e0ed16c6db)

Bug: 23350706
Change-Id: I981d9fa63a0d87eb309485cca93cfc44fc0506cc
2015-08-20 11:31:46 -07:00
Mark Salyzyn a68a5167bc logd: logtimes switch to std::list
(cherry pick from commit 98dca2d0b1)

Bug: 23350706
Change-Id: Icc60dd06119ea20a22610644ff880d5135363aba
2015-08-20 11:30:49 -07:00
Mark Salyzyn edc6f52a89 logd: prune 10% or 256 entries max
(cherry pick from commit b39ed0c992)

Bug: 22351810
Bug: 23327476
Change-Id: I902ba6b431d8b7cee2d65ee2f76e9f7c4f30b152
2015-08-20 11:29:52 -07:00
Mark Salyzyn 8894c395bf logd: sizes > 1M prune in smaller batches
(cherry pick from commit 62ab0fd4ef)

Switch to 1% batch sizes from 10% when individual buffer size > 1M

Bug: 22351810
Change-Id: Ifee570a54643ceb0ba767e1787e937f70cc90b72
2015-08-20 11:28:53 -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 b332f1c427 logd: white and black switch to std::string
Bug: 23350706
Change-Id: I92f21aee0a9702f63e8465851d0f35007b0469a7
2015-08-20 10:25:57 -07:00
Mark Salyzyn c892ea3fa8 logd: worst uid record watermark
Hold on to last worst uid watermark and bypass a spike to O(n*n*x)
(n=samples, x=number of spammers) wrt chatty trimming.

Bug: 23327476
Change-Id: I9f21ce95e969b67e576417a760f75c4d86acf364
2015-08-20 10:25:57 -07:00
Mark Salyzyn 94a89c42fe logd: log buffer switch to std::list
Bug: 23350706
Bug: 23327476
Change-Id: Ib0530b9dd5842c6d05c84d7a66f2531c97461067
2015-08-20 08:36:13 -07:00
Mark Salyzyn e0ed16c6db logd: white and black switch to std::list
Bug: 23350706
Change-Id: I981d9fa63a0d87eb309485cca93cfc44fc0506cc
2015-08-20 08:36:08 -07:00
Mark Salyzyn 98dca2d0b1 logd: logtimes switch to std::list
Bug: 23350706
Change-Id: Icc60dd06119ea20a22610644ff880d5135363aba
2015-08-20 08:36:03 -07:00
Mark Salyzyn b39ed0c992 logd: prune 10% or 256 entries max
Bug: 22351810
Bug: 23327476
Change-Id: I902ba6b431d8b7cee2d65ee2f76e9f7c4f30b152
2015-08-20 08:35:45 -07:00
Mark Salyzyn 1763d1aa78 am e49aba54: am 95e7cb5b: Merge "healthd: logd: add timestamp to kernel logged battery messages"
* commit 'e49aba5413419bbc4f87889edd9a12956a932ef8':
  healthd: logd: add timestamp to kernel logged battery messages
2015-08-12 14:29:01 +00:00
Mark Salyzyn 95e7cb5b8e Merge "healthd: logd: add timestamp to kernel logged battery messages" 2015-08-12 14:17:38 +00:00
Mark Salyzyn 5cfda541dd am c5482138: am ea56594c: Merge "logd: sizes > 1M prune in smaller batches"
* commit 'c54821388d685eff70a466cb01b2e8bb3e6c98fe':
  logd: sizes > 1M prune in smaller batches
2015-08-12 00:04:27 +00:00
Mark Salyzyn 62ab0fd4ef logd: sizes > 1M prune in smaller batches
Switch to 1% batch sizes from 10% when individual buffer size > 1M

Bug: 22351810
Change-Id: Ifee570a54643ceb0ba767e1787e937f70cc90b72
2015-08-11 16:20:54 -07:00
Mark Salyzyn acb1ddf56c healthd: logd: add timestamp to kernel logged battery messages
Aid monotonic to realtime logging synchronization correction in
the Android ecosystem by providing a periodic notification.  We
now have the following messages in the kernel logs:

- PM: suspend entry %Y-%m-%d %H:%M:%S.%09q UTC
- PM: suspend exit %Y-%m-%d %H:%M:%S.%09q UTC
- Suspended for %s.%03q seconds
- healthd: battery l=100 ... %Y-%m-%d %H:%M:%S.%09q UTC

Alter klogd to resynchronize on healthd messages as well.

NB: Time using strftime format, %q is a reference to fractional
second as introduced into log_time strptime method.

Bug: 21868540
Change-Id: I854afc0a07dff9c7f26d2b2f68990e52bf90e300
2015-07-28 16:52:58 -07:00
Mark Salyzyn 6e629e46a1 am f2e86153: am fac3bf35: Merge changes Id65ed2e8,Idbf8fae9
* commit 'f2e86153eda03144f14f75899a5743ec54e667f9':
  liblog: deprecate TARGET_USES_LOGD
  logd: deprecate TARGET_USES_LOGD
2015-07-28 18:31:40 +00:00
Mark Salyzyn cb41e3673b logd: deprecate TARGET_USES_LOGD
This is not the kernel logger you are looking for

Bug: 22787659
Change-Id: Idbf8fae908287ae9a96007b6353ec56d3c49f5bf
2015-07-28 09:37:07 -07:00
Andreas Gampe ba6def6805 am 0c61a650: am 2e132ef6: Merge "Logd: Handle unused variable and fields"
* commit '0c61a650ce8638e6fd7bbbb1ef7ed42e75167194':
  Logd: Handle unused variable and fields
2015-07-28 00:17:05 +00:00
Andreas Gampe d75564f9b8 Logd: Handle unused variable and fields
For build-system CFLAGS clean-up.

Bug: 18632512
Change-Id: If81d6705b44e9a29f64c44c56ea633c031e831b7
2015-07-27 14:17:33 -07:00
Jeff Vander Stoep c200e9564b am 3f62a020: logd: allow logd to write to /dev/cpuset files
* commit '3f62a020c48d5d812fb2898759b93a59dc24d310':
  logd: allow logd to write to /dev/cpuset files
2015-07-24 23:31:53 +00:00
Jeff Vander Stoep 3f62a020c4 logd: allow logd to write to /dev/cpuset files
Required by logd on devices with USE_CPUSETS defined.

Make /dev/cpuset/background, /dev/cpuset/foreground and
/dev/cpuset/task writeable by system gid. Add logd to system
group for writing to cpuset files and to root group to avoid
regressions. When dropping privs, also drop supplementary groups.

Bug: 22699101
Change-Id: Icc01769b18b5e1f1649623da8325a8bfabc3a3f0
2015-07-24 16:22:06 +00:00
Mark Salyzyn 618d0dec50 logd: refine is_prio
- Heuristics associated with translation of kernel messages to
  Android user space logs.
- Limit is_prio to 4 characters, we got false positives on hex
  values like <register contents> with no alpha chars.
- x11 and other register definitions are not valid tags, en0 is
- fix some Android coding standard issues

Change-Id: Idc3dcc53a2cb75ac38628c8ef7a5d5b53f12587a
2015-07-22 07:36:03 -07:00
Mark Salyzyn 5803b79528 logd: serialize accesses to stats helpers
(cherry pick from commit ed777e9eec)

Quick low-risk to resolve possible hash table corruption.
Resolved an unlikely path memory leak.

ToDo: replace lock with nested lock so no lock
      helpers are required.

Bug: 22068332
Change-Id: I303ab06608502c7d61d42f111a9c43366f184d0c
2015-06-25 08:34:06 -07:00
Mark Salyzyn ed777e9eec logd: serialize accesses to stats helpers
Quick low-risk to resolve possible hash table corruption.
Resolved an unlikely path memory leak.

ToDo: replace lock with nested lock so no lock
      helpers are required.

Bug: 22068332
Change-Id: I303ab06608502c7d61d42f111a9c43366f184d0c
2015-06-25 07:39:24 -07:00
Mark Salyzyn d5600fd40f logd: missing klogd content
(cherry pick from commit ee49c6a670)

- regression in log_strtok_r (part deux) In commit
      'logd: fix kernel logline stutter'
  2c3b300fd8 we introduced log_strtok_r.
  as a replacement for strtok_r that dealt with a problem with
  some kernel log messages. Fix is to refine definition of
  is_timestamp to not match on patterns like [0], requiring
  a single period. Another fix is to refine definition of
  is_prio to properly escape non-digit content.
- Missing content because SYSLOG_ACTION_SIZE_BUFFER with added logging
  is too short for full read of SYSLOG_ACTION_READ_ALL dropping
  initial content. Add a margin for additional 1024 bytes.
- Absolute _first_ log entry has sequence number of 1, which is
  specifically dropped, start sequence count at 1 rather than 0.
- Remove trailing space for efficiency.
- If tag exists but no content, trick into kernel logging.

Bug: 21851884
Change-Id: I0867a555a3bca09bbf18d18e75e41dffffe57a23
2015-06-15 14:22:02 -07:00
Mark Salyzyn ee49c6a670 logd: missing klogd content
- regression in log_strtok_r (part deux) In commit
      'logd: fix kernel logline stutter'
  2c3b300fd8 we introduced log_strtok_r.
  as a replacement for strtok_r that dealt with a problem with
  some kernel log messages. Fix is to refine definition of
  is_timestamp to not match on patterns like [0], requiring
  a single period. Another fix is to refine definition of
  is_prio to properly escape non-digit content.
- Missing content because SYSLOG_ACTION_SIZE_BUFFER with added logging
  is too short for full read of SYSLOG_ACTION_READ_ALL dropping
  initial content. Add a margin for additional 1024 bytes.
- Absolute _first_ log entry has sequence number of 1, which is
  specifically dropped, start sequence count at 1 rather than 0.
- Remove trailing space for efficiency.
- If tag exists but no content, trick into kernel logging.

Bug: 21851884
Change-Id: I0867a555a3bca09bbf18d18e75e41dffffe57a23
2015-06-15 21:19:10 +00:00
Mark Salyzyn bd1ef90448 logd: filter on __android_log_is_loggable
(cherry pick from commit e59c469fa8)

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

Bug: 20416721
Bug: 19544788
Bug: 17760225
Change-Id: Icc098e53dc47ceaaeb24ec42eb6f61d6430ec2f6
2015-06-15 07:41:03 -07:00
Mark Salyzyn e59c469fa8 logd: filter on __android_log_is_loggable
- Default level when not specified is ANDROID_LOG_VERBOSE
  which is inert.

Bug: 20416721
Bug: 19544788
Bug: 17760225
Change-Id: Icc098e53dc47ceaaeb24ec42eb6f61d6430ec2f6
2015-06-12 10:35:09 -07:00
Mark Salyzyn 3a1ff5ab65 Merge "Lower the priority of the threads in logd/logcat." into mnc-dev 2015-06-09 19:42:45 +00:00
Riley Andrews aede9897df Lower the priority of the threads in logd/logcat.
(cherry pick from commit d98f4e8af5)

sched_batch implies only a penalty to latency in scheduling, but
does not imply that the process will be given less cpu time. Increase
the nice level to 10 to prioritize it below ui threads.

Bug: 21696721
Change-Id: I075af059dc755402f7df9b0d7a66cca921ff04b2
2015-06-09 12:40:20 -07:00
Riley Andrews d98f4e8af5 Lower the priority of the threads in logd/logcat.
sched_batch implies only a penalty to latency in scheduling, but
does not imply that the process will be given less cpu time. Increase
the nice level to 10 to prioritize it below ui threads.

Bug: 21696721
Change-Id: I075af059dc755402f7df9b0d7a66cca921ff04b2
2015-06-09 12:36:45 -07:00
Mark Salyzyn 03196c9c75 logd: build breakage
(cherry pick from 3e21de2915)

OPEN_BRACKET_SPACE comparison always false

Change-Id: I1ff4288b4b79a49702727d3a8b8c8f179f500951
2015-06-08 14:57:07 -07:00
Mark Salyzyn 3e21de2915 logd: build breakage
OPEN_BRACKET_SPACE comparison always false

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

- look for cases where one log line contains two without a newline.
- rare condition, occurs when a printk does not have
  a terminating newline under certain race conditions.
- the newline may be performed broken up as a second call
- the timestamps can be reversed (showing the race effects).
- driver(s) should really have the newline in their log messages.

Change-Id: Ibfb56b32047da3d6513db059ca6edad0f0105168
2015-06-08 13:55:14 -07:00
Mark Salyzyn 2c3b300fd8 logd: fix kernel logline stutter
- look for cases where one log line contains two without a newline.
- rare condition, occurs when a printk does not have
  a terminating newline under certain race conditions.
- the newline may be performed broken up as a second call
- the timestamps can be reversed (showing the race effects).
- driver(s) should really have the newline in there log messages.

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

- Cleanup resulting from experience and feedback
- When filtering inside logd, drop any leading expire messages, they
  are cluttering up leading edge of tombstones (which filter by pid)
- Increase and introduce EXPIRE_RATELIMIT from 1 to 10 seconds
- Increase EXPIRE_THRESHOLD from 4 to 10 count
- Improve the expire messages from:
   logd : uid=1000(system) too chatty comm=com.google.android.phone,
                                                   expire 2800 lines
  change tag to be more descriptive, and reduce accusatory tone to:
   chatty : uid=1000(system) com.google.android.phone expire 2800
                                                               lines
- if the UID name forms a prefix for comm name, then drop UID name

Change-Id: Ied7cc04c0ab3ae02167649a0b97378e44ef7b588
2015-06-05 10:20:55 -07:00
Mark Salyzyn 047cc0729f logd: filters remove leading expire messages and rate
- Cleanup resulting from experience and feedback
- When filtering inside logd, drop any leading expire messages, they
  are cluttering up leading edge of tombstones (which filter by pid)
- Increase and introduce EXPIRE_RATELIMIT from 1 to 10 seconds
- Increase EXPIRE_THRESHOLD from 4 to 10 count
- Improve the expire messages from:
   logd : uid=1000(system) too chatty comm=com.google.android.phone,
                                                   expire 2800 lines
  change tag to be more descriptive, and reduce accusatory tone to:
   chatty : uid=1000(system) com.google.android.phone expire 2800
                                                               lines
- if the UID name forms a prefix for comm name, then drop UID name

Change-Id: Ied7cc04c0ab3ae02167649a0b97378e44ef7b588
2015-06-05 08:05:05 -07:00
Mark Salyzyn 6f1457adc5 logd: switch to unordered_map from BasicHashtable
(charry pick from commit 511338dd57)

BasicHashtable is relatively untested, move over to
a C++ template library that has more bake time.

Bug: 20419786
Bug: 21590652
Bug: 20500228
Change-Id: I926aaecdc8345eca75c08fdd561b0473504c5d95
2015-06-04 11:03:37 -07:00
Mark Salyzyn 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 49ed105fd9 init.rc: logd: Add logpersistd (nee logcatd)
(cherry pick from commit 100658c303)

- logpersistd is defined as a thread or process in the context of the
  logd domain. Here we define logpersistd as logcat -f in logd domain
  and call it logcatd to represent its service mechanics.
- Use logcatd to manage content in /data/misc/logd/ directory.
- Only turn on for persist.logd.logpersistd = logcatd.
- Add logpersist.start, logpersist.stop and logpersist.cat debug
  class executables, thus only in the eng and userdebug builds.

ToDo: Wish to add Developer Options menu to turn this feature on or
off, complicated by the fact that user builds have no tools with
access rights to /data/misc/logd.

Bug: 19608716
Change-Id: I57ad757f121c473d04f9fabe9d4820a0eca06f31
2015-06-02 15:28:36 -07:00
Mark Salyzyn 100658c303 init.rc: logd: Add logpersistd (nee logcatd)
- logpersistd is defined as a thread or process in the context of the
  logd domain. Here we define logpersistd as logcat -f in logd domain
  and call it logcatd to represent its service mechanics.
- Use logcatd to manage content in /data/misc/logd/ directory.
- Only turn on for persist.logd.logpersistd = logcatd.
- Add logpersist.start, logpersist.stop and logpersist.cat debug
  class executables, thus only in the eng and userdebug builds.

ToDo: Wish to add Developer Options menu to turn this feature on or
off, complicated by the fact that user builds have no tools with
access rights to /data/misc/logd.

Bug: 19608716
Change-Id: I57ad757f121c473d04f9fabe9d4820a0eca06f31
2015-06-02 15:17:59 -07:00
Mark Salyzyn 42ac34f740 logd: test modernization
(cherry pick from commit 62d6a2a921)

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

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

Code in 833a9b1e38 was borken,
simpler approach is to simply check last entry (to save a
syscall) minus EXPIRE_HOUR_THRESHOLD. This does make longer logs
less likely to call upon the spam detection than the algorithm
being replaced, but sadly we ended up with a log entry in the
future at the beginning of the logs confounding the previous
algorithm.

Bug: 21555259
Change-Id: I04fad67e95c8496521dbabb73b5f32c19d6a16c2
2015-06-01 14:27:02 -07:00
Mark Salyzyn d4bdb7df9b logd: deal with sloppy leading expire messages
(cherry pick from commit 5392aac95d)

The odds of chatty content also leading the logs is pretty high eg:

 1799 12017 I logd: uid=10007 chatty comm=Binder_B, expire 4 lines
 1799  1829 I logd: uid=10007 chatty comm=Binder_2, expire 4 lines
 1919 20637 I logd: uid=10007 chatty comm=m.sersistent, expire 1 line
 1919 20638 I logd: uid=10007 chatty comm=s.persistent, expire 1 line
 1919  2316 I logd: uid=10007 chatty comm=UlrDispatch, expire 4 lines
19379 20634 I logd: uid=10045 chatty, expire 14 lines
19379 19388 I logd: uid=10045 chatty comm=lizerDaemon, expire 4 lines
  591  4396 I logd: uid=1000 chatty comm=Thread-220, expire 5 lines
  591  1377 I logd: uid=1000 chatty comm=Thread-92, expire 4 lines
 1919  2267 I logd: uid=10007 chatty comm=WifiScanner, expire 4 lines
  591  4397 I logd: uid=1000 chatty comm=DhcpClient, expire 4 lines
  591  4398 I logd: uid=1000 chatty comm=Thread-222, expire 4 lines
  226   580 D CommandListener: Setting iface cfg

Change-Id: I5ab24bc7bf5d2690bae7e789831b07f23ff8bcc6
2015-06-01 14:27:02 -07:00
Mark Salyzyn a8b6131ddf Merge "logd: test modernization" 2015-06-01 21:16:58 +00:00
Mark Salyzyn 10a124d342 Merge "logd: whitelist should not preserve expire messages" 2015-06-01 21:16:57 +00:00
Mark Salyzyn 5921276a16 logd: KISS & fix preserve a day
Code in 833a9b1e38 was borken,
simpler approach is to simply check last entry (to save a
syscall) minus EXPIRE_HOUR_THRESHOLD. This does make longer logs
less likely to call upon the spam detection than the algorithm
being replaced, but sadly we ended up with a log entry in the
future at the beginning of the logs confounding the previous
algorithm.

Bug: 21555259
Change-Id: I04fad67e95c8496521dbabb73b5f32c19d6a16c2
2015-06-01 13:06:35 -07:00
Mark Salyzyn 5392aac95d logd: deal with sloppy leading expire messages
The odds of chatty content also leading the logs is pretty high eg:

 1799 12017 I logd: uid=10007 chatty comm=Binder_B, expire 4 lines
 1799  1829 I logd: uid=10007 chatty comm=Binder_2, expire 4 lines
 1919 20637 I logd: uid=10007 chatty comm=m.sersistent, expire 1 line
 1919 20638 I logd: uid=10007 chatty comm=s.persistent, expire 1 line
 1919  2316 I logd: uid=10007 chatty comm=UlrDispatch, expire 4 lines
19379 20634 I logd: uid=10045 chatty, expire 14 lines
19379 19388 I logd: uid=10045 chatty comm=lizerDaemon, expire 4 lines
  591  4396 I logd: uid=1000 chatty comm=Thread-220, expire 5 lines
  591  1377 I logd: uid=1000 chatty comm=Thread-92, expire 4 lines
 1919  2267 I logd: uid=10007 chatty comm=WifiScanner, expire 4 lines
  591  4397 I logd: uid=1000 chatty comm=DhcpClient, expire 4 lines
  591  4398 I logd: uid=1000 chatty comm=Thread-222, expire 4 lines
  226   580 D CommandListener: Setting iface cfg

Change-Id: I5ab24bc7bf5d2690bae7e789831b07f23ff8bcc6
2015-06-01 13:04:09 -07:00
Mark Salyzyn 62d6a2a921 logd: test modernization
Bug: 19603976
Change-Id: Ie920c128e7e6a436fea7a96c7d68bc39e13a2ad4
2015-05-26 12:24:51 -07:00
Mark Salyzyn c5bf3b8304 logd: whitelist should not preserve expire messages
Change-Id: I56275c73191b96aa21e7b4049d401e1f44211f9b
2015-05-21 13:01:56 -07:00
Mark Salyzyn 94a811ab19 logd: worst-UID only to preserve a day
(cherry pick from commit 833a9b1e38)

Do not invoke worst-UID pruning in the face of other
UIDs logs that are more than a day old, switch to
pruning oldest only.

Change-Id: Icf988b8d5458400a660d0f8e9d2df3f9d9a4c2d9
2015-05-20 10:03:11 -07:00
Mark Salyzyn 833a9b1e38 logd: worst-UID only to preserve a day
Do not invoke worst-UID pruning in the face of other
UIDs logs that are more than a day old, switch to
pruning oldest only.

Change-Id: Icf988b8d5458400a660d0f8e9d2df3f9d9a4c2d9
2015-05-20 09:47:54 -07:00
Mark Salyzyn 654904f0f9 logd: Add TID statistics
(cherry pick from commit 17ed6797df)

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

- Android Coding Standard for Constructors
- Side effects NONE

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

- Add a klogd to collect the kernel logs and place them into a
  new kernel log buffer
- Parse priority, tag and message from the kernel log messages.
- Turn off pruning for worst UID for the kernel log buffer
- Sniff for 'PM: suspend exit', 'PM: suspend enter' and
  'Suspended for' messages and correct the internal definition
  time correction against monotonic dynamically.
- Discern if we have monotonic or real time (delineation 1980) in
  audit messages.
- perform appropriate math to correct the timestamp to be real time
- filter out any external sources of kernel logging

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

- Optional class of statistics for events Tags
- export tagToName from LogBuffer (located in main.cp to address
  https://android-review.googlesource.com/#/c/110204)
- Can not handle dropped because getTag() can not work,
  will need to be fixed if we start filtering.

Bug: 19608965
Change-Id: I7b90607ca588bf37bab71f19b1570a290e772776
2015-05-12 15:34:56 -07:00
Mark Salyzyn 4fba28671b logd: pidToName deficiency
(Cherry pick from commit aa43ae2268)

any logging in zygote permanently sets the pidToName

Change-Id: I0b8fdc96fb5965a04d4dc4293c39815beef5eb8e
2015-05-12 13:06:25 -07:00
Mark Salyzyn 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 7297278ade Merge "logd: pidToName deficiency" 2015-05-12 19:38:40 +00:00
Mark Salyzyn 9bdc064720 logd: uidToName add dex2oat UID
(cherry pick from commit 023f51f360)

- When searching for uidToName from /data/system/packages.list
  one must search for the uid % AID_USER;
- If uid % AID_USER is greater than AID_SHARED_GID_START - AID_APP,
  then subract it and try again to pick up uidToName.

Change-Id: I24df42957ff7e746fffa5d39484637b1b726b9c0
2015-05-12 09:55:02 -07:00
Mark Salyzyn 80b129f9f0 Merge "logd: uidToName add dex2oat UID" 2015-05-11 23:51:32 +00:00
Nick Kralevich 6de7a06afb Revert "libaudit: limit to 5 selinux denials per sec"
The shamu instabilities continued even after throttling SELinux denials
to 5/second. 5 denials per second is too low when doing device bringup,
and there have been some complaints about lost SELinux denials. See,
for example, http://comments.gmane.org/gmane.comp.security.selinux/21941

Bring the limit back up to 20/second to prevent dropping too many
denials on the floor.

This reverts commit a15db51bbf.

(cherrypick of commit 9667a66019)

Change-Id: I05e85cce0a792d05aa557fcc614c0fc019c15014
2015-05-11 15:43:25 -07:00
Nick Kralevich 9667a66019 Revert "libaudit: limit to 5 selinux denials per sec"
The shamu instabilities continued even after throttling SELinux denials
to 5/second. 5 denials per second is too low when doing device bringup,
and there have been some complaints about lost SELinux denials. See,
for example, http://comments.gmane.org/gmane.comp.security.selinux/21941

Bring the limit back up to 20/second to prevent dropping too many
denials on the floor.

This reverts commit a15db51bbf.

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

Add EntryBase and EntryBaseDropped base classes for statistical
entries to inherit from. Abstract add(), subtract() and drop()
methods to common LogBufferElement in each for entry policy decisions.
Some move of details out of LogStatistics.cpp and place them into
LogStatistics.h. Add statistical add(), subtract() and
drop() methods to hash table to call entries for policy.

Bug: 19608965
Change-Id: Ib8a33a8fe28871ef165d1632c6546a5c606231e8
2015-05-07 10:01:39 -07:00
Mark Salyzyn 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 aa43ae2268 logd: pidToName deficiency
any logging in zygote permanently sets the pidToName

Change-Id: I0b8fdc96fb5965a04d4dc4293c39815beef5eb8e
2015-05-05 12:34:16 -07:00
Mark Salyzyn aaf9c1b3b4 Merge "logd: class hierarcy for Uid and Pid statistics." 2015-05-05 16:47:03 +00:00
Mark Salyzyn 95108f1844 logd: improve details on chatty records
(Cherry pick from commit 21fb7e0b75)

- Report applications UID, TID/PID by name.
- change wording to have an accurate connotation
- drop privilege check since filtered upstream

Bug: 19608965
Bug: 20334069
Bug: 20370119
Change-Id: I2b1c26580b4c2de293874214ff5ae745546f3cca
2015-04-30 15:25:12 -07:00
Mark Salyzyn 5a9d33ee1c logd: reduce chance of dropped 1 messages
- do not time out at 1 second if drop has count of less than 4

(Cherry picked from commit 35173a9ac5)

Bug: 20334069
Bug: 20370119
Change-Id: I787cb553dfab5ed71abd6ed72b63de675f834e0c
2015-04-30 13:24:59 -07:00
Mark Salyzyn 21fb7e0b75 logd: improve details on chatty records
- Report applications UID, TID/PID by name.
- change wording to have an accurate connotation
- drop privilege check since filtered upstream

Bug: 19608965
Bug: 20334069
Bug: 20370119
Change-Id: I2b1c26580b4c2de293874214ff5ae745546f3cca
2015-04-30 13:14:51 -07:00
Mark Salyzyn 35173a9ac5 logd: reduce chance of dropped 1 messages
- do not time out at 1 second if drop has count of less than 4

Bug: 20334069
Bug: 20370119
Change-Id: I787cb553dfab5ed71abd6ed72b63de675f834e0c
2015-04-30 13:14:51 -07:00
Mark Salyzyn 653f9581bf Merge "logd: per UID less aggressive 12.5% threshold" 2015-04-23 14:41:48 +00:00
Mark Salyzyn e06a6e0f26 logd: ratelimit drop messages to 1/sec
Bug: 20334069
Bug: 20370119
Change-Id: I6f850aec46c4df1c99a5b1f28db75d071e134ad5
2015-04-22 11:58:37 -07:00
Mark Salyzyn d717d805d4 logd: per UID less aggressive 12.5% threshold
Per-UID quota has a threshold of 12.5% of the total log size.
If less than that space is taken by the UID, then we
will not engage the pruning based on worst UID.

Change-Id: I9f15c9a26938f1115eb75e9c28ddb073e7680e06
2015-04-22 11:53:29 -07:00
Mark Salyzyn 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 2c9d909a00 logd: better drop message merging
- Former algorithm anlo coalesced adjacent records
- New algorithm maintains a hash list of all drop
  records and coalesces them all.

Bug: 20334069
Bug: 20370119
Change-Id: Idc15ce31fc1087c2cfa39da60c62feade8b88761
2015-04-20 12:58:54 -07:00
Mark Salyzyn 202e153f94 logd: propagate ::log status
Add a return value for the ::log() methods, this allows
us to optimize the wakeup for the readers to only occur
when the log message is actually placed.

This is for a future where we may dedupe identical log
messages, filter out log messages, and certainly if we
filter the messages out with an internal logd check of
__android_log_is_loggable().

Change-Id: I763b2a7c29502ab7fa0a5d5022c7b60244fcfde4
2015-04-15 19:43:28 -07:00
Mark Salyzyn 56c6575da7 Merge "logd: syscall optimization" 2015-04-15 14:45:24 +00:00
Mark Salyzyn c32afdf913 logd: pidToUid incorrect
Change-Id: I9b0e655780924db125568179771e57b01e80aaae
2015-04-14 13:07:29 -07:00
Mark Salyzyn ae76923839 logd: disable worst uid prune for events buffer
There is some usage statistics that would be hurt by pruning by UID,
since _all_ usage statistics come from system_server. In other words
we expect it to be chatty. Until we formulate and evaluate a better
(eg: per-tag?) filtration mechanism, lets hold off pruning by UID.

Bug: 19608965
Change-Id: Iddd45a671e13bdcf3394c20919ad1f2e4ef36616
2015-04-10 15:45:10 -07:00
Mark Salyzyn 1a01f963ff Revert: "logd: default off by-UID spam filter"
With "logd: inject first UID by log buffer message" we can
remove the FUD introduced by having the UID spam filter on

This reverts commit 4141cb2391

Bug: 19608965
Bug: 14469172
Change-Id: Ifdc20b099e0e426546525b11c1dfe8cc0f830a02
2015-04-10 15:45:10 -07:00
Mark Salyzyn ab0dcf6828 logd: annotate worst-UID pruned entries
- internal dropped entries are associated by prune by worst UID
  and are applied by UID and by PID
- track dropped entries by rewriting them in place
- merge similar dropped entries together for same UID(implied),
  PID and TID so that blame can more clearly be placed
- allow aging of dropped entries by the general backgound pruning
- report individual dropped entries formatted to reader
- add statistics to track dropped entries by UID, the combination
  of statistics and dropped logging can track over-the-top Chattiest
  clients.

Bug: 19608965
Change-Id: Ibc68480df0c69c55703270cd70c6b26aea165853
2015-04-10 15:45:08 -07:00
Mark Salyzyn c6637859c2 logd: Build Breakage
a change slipped in from a rebase conflict, repairing.

Change-Id: Ib6479f88fb044f37b6721035c2f7cc75577c0411
2015-04-08 16:09:28 -07:00