summaryrefslogtreecommitdiffstats
diff options
context:
space:
mode:
authorMark Salyzyn2015-02-12 17:14:26 -0600
committerMark Salyzyn2015-03-04 15:21:41 -0600
commitd45d36e011bf2a42bffac07424d3990022287f3c (patch)
tree45ca563150afa1e1d44b6fed19d164ab67db9a9f
parent29eb57066c37bf667a56bb4a7143b50664d5eb44 (diff)
downloadplatform-system-core-d45d36e011bf2a42bffac07424d3990022287f3c.tar.gz
platform-system-core-d45d36e011bf2a42bffac07424d3990022287f3c.tar.xz
platform-system-core-d45d36e011bf2a42bffac07424d3990022287f3c.zip
liblog: Instrument logging of logd write drops
- If logger system is prostrated, send an event message with the liblog tag from the associated UID and PID with a count of dropped messages once logging is resumed. - Added to the README a description of the error return values. - Describe in the README the appropriate mitigations for dropped messages. - If the caller sees this message, then /proc/sys/net/unix/max_dgram_qlen is likely too small Change-Id: Iaf387b9e5e1b6aa93bebc7481f9e8353732e3229
-rw-r--r--liblog/Android.mk10
-rw-r--r--liblog/README27
-rw-r--r--liblog/event.logtags36
-rw-r--r--liblog/logd_write.c28
4 files changed, 96 insertions, 5 deletions
diff --git a/liblog/Android.mk b/liblog/Android.mk
index 5756c54d5..9353546dc 100644
--- a/liblog/Android.mk
+++ b/liblog/Android.mk
@@ -16,6 +16,8 @@
16LOCAL_PATH := $(my-dir) 16LOCAL_PATH := $(my-dir)
17include $(CLEAR_VARS) 17include $(CLEAR_VARS)
18 18
19liblog_cflags := $(shell sed -n 's/^\([0-9]*\)[ \t]*liblog[ \t].*/-DLIBLOG_LOG_TAG=\1/p' $(LOCAL_PATH)/event.logtags)
20
19ifneq ($(TARGET_USES_LOGD),false) 21ifneq ($(TARGET_USES_LOGD),false)
20liblog_sources := logd_write.c 22liblog_sources := logd_write.c
21else 23else
@@ -45,7 +47,7 @@ else
45 uio.c 47 uio.c
46endif 48endif
47 49
48liblog_host_sources := $(liblog_sources) fake_log_device.c 50liblog_host_sources := $(liblog_sources) fake_log_device.c event.logtags
49liblog_target_sources := $(liblog_sources) log_time.cpp log_is_loggable.c 51liblog_target_sources := $(liblog_sources) log_time.cpp log_is_loggable.c
50ifneq ($(TARGET_USES_LOGD),false) 52ifneq ($(TARGET_USES_LOGD),false)
51liblog_target_sources += log_read.c 53liblog_target_sources += log_read.c
@@ -57,7 +59,7 @@ endif
57# ======================================================== 59# ========================================================
58LOCAL_MODULE := liblog 60LOCAL_MODULE := liblog
59LOCAL_SRC_FILES := $(liblog_host_sources) 61LOCAL_SRC_FILES := $(liblog_host_sources)
60LOCAL_CFLAGS := -DFAKE_LOG_DEVICE=1 -Werror 62LOCAL_CFLAGS := -DFAKE_LOG_DEVICE=1 -Werror $(liblog_cflags)
61LOCAL_MULTILIB := both 63LOCAL_MULTILIB := both
62include $(BUILD_HOST_STATIC_LIBRARY) 64include $(BUILD_HOST_STATIC_LIBRARY)
63 65
@@ -76,13 +78,13 @@ include $(BUILD_HOST_SHARED_LIBRARY)
76include $(CLEAR_VARS) 78include $(CLEAR_VARS)
77LOCAL_MODULE := liblog 79LOCAL_MODULE := liblog
78LOCAL_SRC_FILES := $(liblog_target_sources) 80LOCAL_SRC_FILES := $(liblog_target_sources)
79LOCAL_CFLAGS := -Werror 81LOCAL_CFLAGS := -Werror $(liblog_cflags)
80include $(BUILD_STATIC_LIBRARY) 82include $(BUILD_STATIC_LIBRARY)
81 83
82include $(CLEAR_VARS) 84include $(CLEAR_VARS)
83LOCAL_MODULE := liblog 85LOCAL_MODULE := liblog
84LOCAL_WHOLE_STATIC_LIBRARIES := liblog 86LOCAL_WHOLE_STATIC_LIBRARIES := liblog
85LOCAL_CFLAGS := -Werror 87LOCAL_CFLAGS := -Werror $(liblog_cflags)
86include $(BUILD_SHARED_LIBRARY) 88include $(BUILD_SHARED_LIBRARY)
87 89
88include $(call first-makefiles-under,$(LOCAL_PATH)) 90include $(call first-makefiles-under,$(LOCAL_PATH))
diff --git a/liblog/README b/liblog/README
index 461dfbe98..f29ac045b 100644
--- a/liblog/README
+++ b/liblog/README
@@ -131,6 +131,33 @@ DESCRIPTION
131 when opening the sub-log. It is recommended to open the log 131 when opening the sub-log. It is recommended to open the log
132 ANDROID_LOG_RDONLY in these cases. 132 ANDROID_LOG_RDONLY in these cases.
133 133
134ERRORS
135 If messages fail, a negative error code will be returned to the caller.
136
137 The -ENOTCONN return code indicates that the logger daemon is stopped.
138
139 The -EBADF return code indicates that the log access point can not be
140 opened, or the log buffer id is out of range.
141
142 For the -EAGAIN return code, this means that the logging message was
143 temporarily backed-up either because of Denial Of Service (DOS) logging
144 pressure from some chatty application or service in the Android system,
145 or if too small of a value is set in /proc/sys/net/unix/max_dgram_qlen.
146 To aid in diagnosing the occurence of this, a binary event from liblog
147 will be sent to the log daemon once a new message can get through
148 indicating how many messages were dropped as a result. Please take
149 action to resolve the structural problems at the source.
150
151 It is generally not advised for the caller to retry the -EAGAIN return
152 code as this will only make the problem(s) worse and cause your
153 application to temporarily drop to the logger daemon priority, BATCH
154 scheduling policy and background task cgroup. If you require a group of
155 messages to be passed atomically, merge them into one message with
156 embedded newlines to the maximum length LOGGER_ENTRY_MAX_PAYLOAD.
157
158 Other return codes from writing operation can be returned. Since the
159 library retries on EINTR, -EINTR should never be returned.
160
134SEE ALSO 161SEE ALSO
135 syslogd(8) 162 syslogd(8)
136 163
diff --git a/liblog/event.logtags b/liblog/event.logtags
new file mode 100644
index 000000000..72ecab198
--- /dev/null
+++ b/liblog/event.logtags
@@ -0,0 +1,36 @@
1# The entries in this file map a sparse set of log tag numbers to tag names.
2# This is installed on the device, in /system/etc, and parsed by logcat.
3#
4# Tag numbers are decimal integers, from 0 to 2^31. (Let's leave the
5# negative values alone for now.)
6#
7# Tag names are one or more ASCII letters and numbers or underscores, i.e.
8# "[A-Z][a-z][0-9]_". Do not include spaces or punctuation (the former
9# impacts log readability, the latter makes regex searches more annoying).
10#
11# Tag numbers and names are separated by whitespace. Blank lines and lines
12# starting with '#' are ignored.
13#
14# Optionally, after the tag names can be put a description for the value(s)
15# of the tag. Description are in the format
16# (<name>|data type[|data unit])
17# Multiple values are separated by commas.
18#
19# The data type is a number from the following values:
20# 1: int
21# 2: long
22# 3: string
23# 4: list
24#
25# The data unit is a number taken from the following list:
26# 1: Number of objects
27# 2: Number of bytes
28# 3: Number of milliseconds
29# 4: Number of allocations
30# 5: Id
31# 6: Percent
32# Default value for data of type int/long is 2 (bytes).
33#
34# TODO: generate ".java" and ".h" files with integer constants from this file.
35
361005 liblog (dropped|1)
diff --git a/liblog/logd_write.c b/liblog/logd_write.c
index 0208c7389..c8a6162b7 100644
--- a/liblog/logd_write.c
+++ b/liblog/logd_write.c
@@ -13,12 +13,14 @@
13 * See the License for the specific language governing permissions and 13 * See the License for the specific language governing permissions and
14 * limitations under the License. 14 * limitations under the License.
15 */ 15 */
16#include <endian.h>
16#include <errno.h> 17#include <errno.h>
17#include <fcntl.h> 18#include <fcntl.h>
18#if !defined(_WIN32) 19#if !defined(_WIN32)
19#include <pthread.h> 20#include <pthread.h>
20#endif 21#endif
21#include <stdarg.h> 22#include <stdarg.h>
23#include <stdatomic.h>
22#include <stdio.h> 24#include <stdio.h>
23#include <stdlib.h> 25#include <stdlib.h>
24#include <string.h> 26#include <string.h>
@@ -172,6 +174,7 @@ static int __write_to_log_daemon(log_id_t log_id, struct iovec *vec, size_t nr)
172 size_t i, payload_size; 174 size_t i, payload_size;
173 static uid_t last_uid = AID_ROOT; /* logd *always* starts up as AID_ROOT */ 175 static uid_t last_uid = AID_ROOT; /* logd *always* starts up as AID_ROOT */
174 static pid_t last_pid = (pid_t) -1; 176 static pid_t last_pid = (pid_t) -1;
177 static atomic_int_fast32_t dropped;
175 178
176 if (last_uid == AID_ROOT) { /* have we called to get the UID yet? */ 179 if (last_uid == AID_ROOT) { /* have we called to get the UID yet? */
177 last_uid = getuid(); 180 last_uid = getuid();
@@ -206,7 +209,6 @@ static int __write_to_log_daemon(log_id_t log_id, struct iovec *vec, size_t nr)
206 pmsg_header.uid = last_uid; 209 pmsg_header.uid = last_uid;
207 pmsg_header.pid = last_pid; 210 pmsg_header.pid = last_pid;
208 211
209 header.id = log_id;
210 header.tid = gettid(); 212 header.tid = gettid();
211 header.realtime.tv_sec = ts.tv_sec; 213 header.realtime.tv_sec = ts.tv_sec;
212 header.realtime.tv_nsec = ts.tv_nsec; 214 header.realtime.tv_nsec = ts.tv_nsec;
@@ -216,6 +218,28 @@ static int __write_to_log_daemon(log_id_t log_id, struct iovec *vec, size_t nr)
216 newVec[1].iov_base = (unsigned char *) &header; 218 newVec[1].iov_base = (unsigned char *) &header;
217 newVec[1].iov_len = sizeof(header); 219 newVec[1].iov_len = sizeof(header);
218 220
221 if (logd_fd > 0) {
222 int32_t snapshot = atomic_exchange_explicit(&dropped, 0, memory_order_relaxed);
223 if (snapshot) {
224 android_log_event_int_t buffer;
225
226 header.id = LOG_ID_EVENTS;
227 buffer.header.tag = htole32(LIBLOG_LOG_TAG);
228 buffer.payload.type = EVENT_TYPE_INT;
229 buffer.payload.data = htole32(snapshot);
230
231 newVec[2].iov_base = &buffer;
232 newVec[2].iov_len = sizeof(buffer);
233
234 ret = TEMP_FAILURE_RETRY(writev(logd_fd, newVec + 1, 2));
235 if (ret != (ssize_t)(sizeof(header) + sizeof(buffer))) {
236 atomic_fetch_add_explicit(&dropped, snapshot, memory_order_relaxed);
237 }
238 }
239 }
240
241 header.id = log_id;
242
219 for (payload_size = 0, i = header_length; i < nr + header_length; i++) { 243 for (payload_size = 0, i = header_length; i < nr + header_length; i++) {
220 newVec[i].iov_base = vec[i - header_length].iov_base; 244 newVec[i].iov_base = vec[i - header_length].iov_base;
221 payload_size += newVec[i].iov_len = vec[i - header_length].iov_len; 245 payload_size += newVec[i].iov_len = vec[i - header_length].iov_len;
@@ -281,6 +305,8 @@ static int __write_to_log_daemon(log_id_t log_id, struct iovec *vec, size_t nr)
281 305
282 if (ret > (ssize_t)sizeof(header)) { 306 if (ret > (ssize_t)sizeof(header)) {
283 ret -= sizeof(header); 307 ret -= sizeof(header);
308 } else if (ret == -EAGAIN) {
309 atomic_fetch_add_explicit(&dropped, 1, memory_order_relaxed);
284 } 310 }
285#endif 311#endif
286 312