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
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
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
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
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
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
- 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
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>
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
- 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
- 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
- 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
- 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
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
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
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
* 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
* 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
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
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
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
(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
(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
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
(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
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
(cherry pick from commit ccfe8446a1)
Regression that cause records to be preserved for more than a day.
Bug: 23681639
Bug: 23685592
Change-Id: I5e4393c8e3ed935790994c77ec51dc6512a6daa6
(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
(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
(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
- 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
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
* 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
(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
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
Mark Salyzyn