Commit graph

16 commits

Author SHA1 Message Date
Mark Salyzyn
ddb842ac93 logd: klogd: parse error
(cherry pick from commit eb29808615)

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-16 12:48:58 -08:00
Mark Salyzyn
c48d249c37 liblog: logd: support logd.timestamp = monotonic
(cherry pick from commit b6bee33182)

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-16 08:53:51 -08:00
Mark Salyzyn
f9162cf711 logd: optimize code hotspots
(cherry pick from commit ddda212faa)

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-11-16 08:53:04 -08:00
Mark Salyzyn
4efc87e5eb logd: klogd deal with nuls in dmesg
(cherry pick from commit 151beac76d)

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-11-16 08:53:04 -08:00
Mark Salyzyn
f9e4d0b6b5 logd: log_strtok_r deal with nuls
(cherry pick from commit ea1a241107)

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-11-16 08:53:04 -08:00
Mark Salyzyn
3f78f93302 logd: klogd: sniff for time correction on Mediatek
(cherry pick from commit 2d159bf3b5)

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-11-16 08:53:04 -08:00
Mark Salyzyn
540cfe8e6b logd: klogd and Mediatek part deux
(cherry pick from commit 47dba71f24)

- switch to an open coded strnrchr
- validity checking on n, taglen and b values.

Bug: 23517551
Change-Id: I568e25c5aa6d8474835454a0e83b19c2921b7986
2015-11-16 08:53:04 -08:00
Andreas Gampe
244f32fa2d Logd: Handle unused variable and fields
(cherry pick from commit d75564f9b8)

For build-system CFLAGS clean-up.

Bug: 18632512
Change-Id: If81d6705b44e9a29f64c44c56ea633c031e831b7
2015-11-16 08:53:04 -08: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
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
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
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
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
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