Commit graph

219 commits

Author SHA1 Message Date
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
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
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
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
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
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
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
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
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
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
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
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
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