1 /*
2 * Copyright (C) 2018 The Android Open Source Project
3 *
4 * Licensed under the Apache License, Version 2.0 (the "License");
5 * you may not use this file except in compliance with the License.
6 * You may obtain a copy of the License at
7 *
8 * http://www.apache.org/licenses/LICENSE-2.0
9 *
10 * Unless required by applicable law or agreed to in writing, software
11 * distributed under the License is distributed on an "AS IS" BASIS,
12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13 * See the License for the specific language governing permissions and
14 * limitations under the License.
15 */
16 #define STATSD_DEBUG false // STOPSHIP if true
17 #include "Log.h"
18
19 #include "StatsSocketListener.h"
20
21 #include <ctype.h>
22 #include <cutils/sockets.h>
23 #include <limits.h>
24 #include <stdio.h>
25 #include <sys/cdefs.h>
26 #include <sys/prctl.h>
27 #include <sys/socket.h>
28 #include <sys/types.h>
29 #include <sys/un.h>
30 #include <unistd.h>
31
32 #include "guardrail/StatsdStats.h"
33 #include "logd/logevent_util.h"
34 #include "stats_log_util.h"
35 #include "statslog_statsd.h"
36 #include "utils/api_tracing.h"
37
38 using namespace std;
39
40 namespace android {
41 namespace os {
42 namespace statsd {
43
StatsSocketListener(const std::shared_ptr<LogEventQueue> & queue,const std::shared_ptr<LogEventFilter> & logEventFilter)44 StatsSocketListener::StatsSocketListener(const std::shared_ptr<LogEventQueue>& queue,
45 const std::shared_ptr<LogEventFilter>& logEventFilter)
46 : SocketListener(getLogSocket(), false /*start listen*/),
47 mQueue(queue),
48 mLogEventFilter(logEventFilter),
49 mLastSocketReadTimeNs(0) {
50 }
51
onDataAvailable(SocketClient * cli)52 bool StatsSocketListener::onDataAvailable(SocketClient* cli) {
53 ATRACE_CALL();
54 static bool name_set;
55 if (!name_set) {
56 prctl(PR_SET_NAME, "statsd.writer");
57 name_set = true;
58 }
59
60 int64_t elapsedTimeNs = getElapsedRealtimeNs();
61 // + 1 to ensure null terminator if MAX_PAYLOAD buffer is received
62 char buffer[sizeof(android_log_header_t) + LOGGER_ENTRY_MAX_PAYLOAD + 1];
63 struct iovec iov = {buffer, sizeof(buffer) - 1};
64
65 alignas(4) char control[CMSG_SPACE(sizeof(struct ucred))];
66 struct msghdr hdr = {
67 NULL, 0, &iov, 1, control, sizeof(control), 0,
68 };
69
70 const int socket = cli->getSocket();
71 int i = 0;
72 int64_t minAtomReadTime = INT64_MAX;
73 int64_t maxAtomReadTime = -1;
74 mAtomCounts.clear();
75 ssize_t n = 0;
76 while (n = recvmsg(socket, &hdr, MSG_DONTWAIT), n > 0) {
77 // To clear the entire buffer is secure/safe, but this contributes to 1.68%
78 // overhead under logging load. We are safe because we check counts, but
79 // still need to clear null terminator.
80 // Note that the memset, if needed, should happen before each read in the while loop.
81 // memset(buffer, 0, sizeof(buffer));
82 if (n <= (ssize_t)(sizeof(android_log_header_t))) {
83 return false;
84 }
85 buffer[n] = 0;
86 i++;
87
88 struct ucred* cred = NULL;
89
90 struct cmsghdr* cmsg = CMSG_FIRSTHDR(&hdr);
91 while (cmsg != NULL) {
92 if (cmsg->cmsg_level == SOL_SOCKET && cmsg->cmsg_type == SCM_CREDENTIALS) {
93 cred = (struct ucred*)CMSG_DATA(cmsg);
94 break;
95 }
96 cmsg = CMSG_NXTHDR(&hdr, cmsg);
97 }
98
99 struct ucred fake_cred;
100 if (cred == NULL) {
101 cred = &fake_cred;
102 cred->pid = 0;
103 cred->uid = DEFAULT_OVERFLOWUID;
104 }
105
106 const uint32_t uid = cred->uid;
107 const uint32_t pid = cred->pid;
108
109 auto [atomId, atomTimeNs] =
110 processSocketMessage(buffer, n, uid, pid, *mQueue, *mLogEventFilter);
111 mAtomCounts[atomId]++;
112 minAtomReadTime = min(minAtomReadTime, atomTimeNs);
113 maxAtomReadTime = max(maxAtomReadTime, atomTimeNs);
114 }
115
116 StatsdStats::getInstance().noteBatchSocketRead(i, mLastSocketReadTimeNs, elapsedTimeNs,
117 minAtomReadTime, maxAtomReadTime, mAtomCounts);
118 mLastSocketReadTimeNs = elapsedTimeNs;
119 mAtomCounts.clear();
120 return true;
121 }
122
processSocketMessage(const char * buffer,const uint32_t len,uint32_t uid,uint32_t pid,LogEventQueue & queue,const LogEventFilter & filter)123 tuple<int32_t, int64_t> StatsSocketListener::processSocketMessage(const char* buffer,
124 const uint32_t len, uint32_t uid,
125 uint32_t pid,
126 LogEventQueue& queue,
127 const LogEventFilter& filter) {
128 ATRACE_CALL();
129 static const uint32_t kStatsEventTag = 1937006964;
130
131 if (len <= (ssize_t)(sizeof(android_log_header_t)) + sizeof(uint32_t)) {
132 return {-1, 0};
133 }
134
135 const uint8_t* ptr = ((uint8_t*)buffer) + sizeof(android_log_header_t);
136 uint32_t bufferLen = len - sizeof(android_log_header_t);
137
138 // When a log failed to write to statsd socket (e.g., due ot EBUSY), a special message would
139 // be sent to statsd when the socket communication becomes available again.
140 // The format is android_log_event_int_t with a single integer in the payload indicating the
141 // number of logs that failed. (*FORMAT MUST BE IN SYNC WITH system/core/libstats*)
142 // Note that all normal stats logs are in the format of event_list, so there won't be confusion.
143 //
144 // TODO(b/80538532): In addition to log it in StatsdStats, we should properly reset the config.
145 if (bufferLen == sizeof(android_log_event_long_t)) {
146 const android_log_event_long_t* long_event =
147 reinterpret_cast<const android_log_event_long_t*>(ptr);
148 if (long_event->payload.type == EVENT_TYPE_LONG) {
149 int64_t composed_long = long_event->payload.data;
150
151 // format:
152 // |last_tag|dropped_count|
153 int32_t dropped_count = (int32_t)(0xffffffff & composed_long);
154 int32_t last_atom_tag = (int32_t)((0xffffffff00000000 & (uint64_t)composed_long) >> 32);
155
156 ALOGE("Found dropped events: %d error %d last atom tag %d from uid %d", dropped_count,
157 long_event->header.tag, last_atom_tag, uid);
158 StatsdStats::getInstance().noteLogLost((int32_t)getWallClockSec(), dropped_count,
159 long_event->header.tag, last_atom_tag, uid, pid);
160 return {-1, 0};
161 }
162 }
163
164 // test that received valid StatsEvent buffer
165 const uint32_t statsEventTag = *reinterpret_cast<const uint32_t*>(ptr);
166 if (statsEventTag != kStatsEventTag) {
167 return {-1, 0};
168 }
169
170 // move past the 4-byte StatsEventTag
171 const uint8_t* msg = ptr + sizeof(uint32_t);
172 bufferLen -= sizeof(uint32_t);
173
174 return processStatsEventBuffer(msg, bufferLen, uid, pid, queue, filter);
175 }
176
processStatsEventBuffer(const uint8_t * msg,const uint32_t len,uint32_t uid,uint32_t pid,LogEventQueue & queue,const LogEventFilter & filter)177 tuple<int32_t, int64_t> StatsSocketListener::processStatsEventBuffer(const uint8_t* msg,
178 const uint32_t len,
179 uint32_t uid, uint32_t pid,
180 LogEventQueue& queue,
181 const LogEventFilter& filter) {
182 ATRACE_CALL();
183 std::unique_ptr<LogEvent> logEvent = std::make_unique<LogEvent>(uid, pid);
184
185 if (filter.getFilteringEnabled()) {
186 const LogEvent::BodyBufferInfo bodyInfo = logEvent->parseHeader(msg, len);
187 if (filter.isAtomInUse(logEvent->GetTagId())) {
188 logEvent->parseBody(bodyInfo);
189 }
190 } else {
191 logEvent->parseBuffer(msg, len);
192 }
193
194 const int32_t atomId = logEvent->GetTagId();
195 const bool isAtomSkipped = logEvent->isParsedHeaderOnly();
196 const int64_t atomTimestamp = logEvent->GetElapsedTimestampNs();
197
198 if (atomId == util::STATS_SOCKET_LOSS_REPORTED) {
199 if (isAtomSkipped) {
200 ALOGW("Atom STATS_SOCKET_LOSS_REPORTED should not be skipped");
201 }
202
203 // handling socket loss info reported atom
204 // processing it here to not lose info due to queue overflow
205 const std::optional<SocketLossInfo>& lossInfo = toSocketLossInfo(*logEvent);
206 if (lossInfo) {
207 StatsdStats::getInstance().noteAtomSocketLoss(*lossInfo);
208 } else {
209 ALOGW("Atom STATS_SOCKET_LOSS_REPORTED content is invalid");
210 }
211 }
212
213 const auto [success, oldestTimestamp, queueSize] = queue.push(std::move(logEvent));
214 if (success) {
215 StatsdStats::getInstance().noteEventQueueSize(queueSize, atomTimestamp);
216 } else {
217 StatsdStats::getInstance().noteEventQueueOverflow(oldestTimestamp, atomId, isAtomSkipped);
218 }
219 return {atomId, atomTimestamp};
220 }
221
getLogSocket()222 int StatsSocketListener::getLogSocket() {
223 static const char socketName[] = "statsdw";
224 int sock = android_get_control_socket(socketName);
225
226 if (sock < 0) { // statsd started up in init.sh
227 sock = socket_local_server(socketName, ANDROID_SOCKET_NAMESPACE_RESERVED, SOCK_DGRAM);
228
229 int on = 1;
230 if (setsockopt(sock, SOL_SOCKET, SO_PASSCRED, &on, sizeof(on))) {
231 return -1;
232 }
233 }
234 return sock;
235 }
236
237 } // namespace statsd
238 } // namespace os
239 } // namespace android
240