1 /*
2  * Copyright (C) 2014 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 
17 #include <ctype.h>
18 #include <endian.h>
19 #include <errno.h>
20 #include <limits.h>
21 #include <stdarg.h>
22 #include <stdlib.h>
23 #include <string.h>
24 #include <sys/prctl.h>
25 #include <sys/uio.h>
26 #include <syslog.h>
27 
28 #include <fstream>
29 #include <sstream>
30 
31 #include <android-base/macros.h>
32 #include <log/log_properties.h>
33 #include <private/android_filesystem_config.h>
34 #include <private/android_logger.h>
35 
36 #include "LogAudit.h"
37 #include "LogBuffer.h"
38 #include "LogKlog.h"
39 #include "LogReader.h"
40 #include "LogUtils.h"
41 #include "libaudit.h"
42 
43 #define KMSG_PRIORITY(PRI)                               \
44     '<', '0' + LOG_MAKEPRI(LOG_AUTH, LOG_PRI(PRI)) / 10, \
45         '0' + LOG_MAKEPRI(LOG_AUTH, LOG_PRI(PRI)) % 10, '>'
46 
LogAudit(LogBuffer * buf,LogReader * reader,int fdDmesg)47 LogAudit::LogAudit(LogBuffer* buf, LogReader* reader, int fdDmesg)
48     : SocketListener(getLogSocket(), false),
49       logbuf(buf),
50       reader(reader),
51       fdDmesg(fdDmesg),
52       main(__android_logger_property_get_bool("ro.logd.auditd.main",
53                                               BOOL_DEFAULT_TRUE)),
54       events(__android_logger_property_get_bool("ro.logd.auditd.events",
55                                                 BOOL_DEFAULT_TRUE)),
56       initialized(false) {
57     static const char auditd_message[] = { KMSG_PRIORITY(LOG_INFO),
58                                            'l',
59                                            'o',
60                                            'g',
61                                            'd',
62                                            '.',
63                                            'a',
64                                            'u',
65                                            'd',
66                                            'i',
67                                            't',
68                                            'd',
69                                            ':',
70                                            ' ',
71                                            's',
72                                            't',
73                                            'a',
74                                            'r',
75                                            't',
76                                            '\n' };
77     write(fdDmesg, auditd_message, sizeof(auditd_message));
78 }
79 
onDataAvailable(SocketClient * cli)80 bool LogAudit::onDataAvailable(SocketClient* cli) {
81     if (!initialized) {
82         prctl(PR_SET_NAME, "logd.auditd");
83         initialized = true;
84     }
85 
86     struct audit_message rep;
87 
88     rep.nlh.nlmsg_type = 0;
89     rep.nlh.nlmsg_len = 0;
90     rep.data[0] = '\0';
91 
92     if (audit_get_reply(cli->getSocket(), &rep, GET_REPLY_BLOCKING, 0) < 0) {
93         SLOGE("Failed on audit_get_reply with error: %s", strerror(errno));
94         return false;
95     }
96 
97     logPrint("type=%d %.*s", rep.nlh.nlmsg_type, rep.nlh.nlmsg_len, rep.data);
98 
99     return true;
100 }
101 
hasMetadata(char * str,int str_len)102 static inline bool hasMetadata(char* str, int str_len) {
103     // need to check and see if str already contains bug metadata from
104     // possibility of stuttering if log audit crashes and then reloads kernel
105     // messages. Kernel denials that contain metadata will either end in
106     // "b/[0-9]+$" or "b/[0-9]+  duplicate messages suppressed$" which will put
107     // a '/' character at either 9 or 39 indices away from the end of the str.
108     return str_len >= 39 &&
109            (str[str_len - 9] == '/' || str[str_len - 39] == '/');
110 }
111 
populateDenialMap()112 std::map<std::string, std::string> LogAudit::populateDenialMap() {
113     std::ifstream bug_file("/system/etc/selinux/selinux_denial_metadata");
114     std::string line;
115     // allocate a map for the static map pointer in logParse to keep track of,
116     // this function only runs once
117     std::map<std::string, std::string> denial_to_bug;
118     if (bug_file.good()) {
119         std::string scontext;
120         std::string tcontext;
121         std::string tclass;
122         std::string bug_num;
123         while (std::getline(bug_file, line)) {
124             std::stringstream split_line(line);
125             split_line >> scontext >> tcontext >> tclass >> bug_num;
126             denial_to_bug.emplace(scontext + tcontext + tclass, bug_num);
127         }
128     }
129     return denial_to_bug;
130 }
131 
denialParse(const std::string & denial,char terminator,const std::string & search_term)132 std::string LogAudit::denialParse(const std::string& denial, char terminator,
133                                   const std::string& search_term) {
134     size_t start_index = denial.find(search_term);
135     if (start_index != std::string::npos) {
136         start_index += search_term.length();
137         return denial.substr(
138             start_index, denial.find(terminator, start_index) - start_index);
139     }
140     return "";
141 }
142 
logParse(const std::string & string,std::string * bug_num)143 void LogAudit::logParse(const std::string& string, std::string* bug_num) {
144     if (!__android_log_is_debuggable()) {
145         bug_num->assign("");
146         return;
147     }
148     static std::map<std::string, std::string> denial_to_bug =
149         populateDenialMap();
150     std::string scontext = denialParse(string, ':', "scontext=u:object_r:");
151     std::string tcontext = denialParse(string, ':', "tcontext=u:object_r:");
152     std::string tclass = denialParse(string, ' ', "tclass=");
153     if (scontext.empty()) {
154         scontext = denialParse(string, ':', "scontext=u:r:");
155     }
156     if (tcontext.empty()) {
157         tcontext = denialParse(string, ':', "tcontext=u:r:");
158     }
159     auto search = denial_to_bug.find(scontext + tcontext + tclass);
160     if (search != denial_to_bug.end()) {
161         bug_num->assign(" b/" + search->second);
162     } else {
163         bug_num->assign("");
164     }
165 }
166 
logPrint(const char * fmt,...)167 int LogAudit::logPrint(const char* fmt, ...) {
168     if (fmt == NULL) {
169         return -EINVAL;
170     }
171 
172     va_list args;
173 
174     char* str = NULL;
175     va_start(args, fmt);
176     int rc = vasprintf(&str, fmt, args);
177     va_end(args);
178 
179     if (rc < 0) {
180         return rc;
181     }
182     char* cp;
183     // Work around kernels missing
184     // https://github.com/torvalds/linux/commit/b8f89caafeb55fba75b74bea25adc4e4cd91be67
185     // Such kernels improperly add newlines inside audit messages.
186     while ((cp = strchr(str, '\n'))) {
187         *cp = ' ';
188     }
189 
190     while ((cp = strstr(str, "  "))) {
191         memmove(cp, cp + 1, strlen(cp + 1) + 1);
192     }
193     bool info = strstr(str, " permissive=1") || strstr(str, " policy loaded ");
194     static std::string bug_metadata;
195     if ((fdDmesg >= 0) && initialized) {
196         struct iovec iov[4];
197         static const char log_info[] = { KMSG_PRIORITY(LOG_INFO) };
198         static const char log_warning[] = { KMSG_PRIORITY(LOG_WARNING) };
199         static const char newline[] = "\n";
200 
201         // Dedupe messages, checking for identical messages starting with avc:
202         static unsigned count;
203         static char* last_str;
204         static bool last_info;
205 
206         if (last_str != NULL) {
207             static const char avc[] = "): avc: ";
208             char* avcl = strstr(last_str, avc);
209             bool skip = false;
210 
211             if (avcl) {
212                 char* avcr = strstr(str, avc);
213 
214                 skip = avcr &&
215                        !fastcmp<strcmp>(avcl + strlen(avc), avcr + strlen(avc));
216                 if (skip) {
217                     ++count;
218                     free(last_str);
219                     last_str = strdup(str);
220                     last_info = info;
221                 }
222             }
223             if (!skip) {
224                 static const char resume[] = " duplicate messages suppressed\n";
225                 iov[0].iov_base = last_info ? const_cast<char*>(log_info)
226                                             : const_cast<char*>(log_warning);
227                 iov[0].iov_len =
228                     last_info ? sizeof(log_info) : sizeof(log_warning);
229                 iov[1].iov_base = last_str;
230                 iov[1].iov_len = strlen(last_str);
231                 iov[2].iov_base = const_cast<char*>(bug_metadata.c_str());
232                 iov[2].iov_len = bug_metadata.length();
233                 if (count > 1) {
234                     iov[3].iov_base = const_cast<char*>(resume);
235                     iov[3].iov_len = strlen(resume);
236                 } else {
237                     iov[3].iov_base = const_cast<char*>(newline);
238                     iov[3].iov_len = strlen(newline);
239                 }
240 
241                 writev(fdDmesg, iov, arraysize(iov));
242                 free(last_str);
243                 last_str = NULL;
244             }
245         }
246         if (last_str == NULL) {
247             count = 0;
248             last_str = strdup(str);
249             last_info = info;
250         }
251         if (count == 0) {
252             logParse(str, &bug_metadata);
253             iov[0].iov_base = info ? const_cast<char*>(log_info)
254                                    : const_cast<char*>(log_warning);
255             iov[0].iov_len = info ? sizeof(log_info) : sizeof(log_warning);
256             iov[1].iov_base = str;
257             iov[1].iov_len = strlen(str);
258             iov[2].iov_base = const_cast<char*>(bug_metadata.c_str());
259             iov[2].iov_len = bug_metadata.length();
260             iov[3].iov_base = const_cast<char*>(newline);
261             iov[3].iov_len = strlen(newline);
262 
263             writev(fdDmesg, iov, arraysize(iov));
264         }
265     }
266 
267     if (!main && !events) {
268         free(str);
269         return 0;
270     }
271 
272     pid_t pid = getpid();
273     pid_t tid = gettid();
274     uid_t uid = AID_LOGD;
275     log_time now;
276 
277     static const char audit_str[] = " audit(";
278     char* timeptr = strstr(str, audit_str);
279     if (timeptr &&
280         ((cp = now.strptime(timeptr + sizeof(audit_str) - 1, "%s.%q"))) &&
281         (*cp == ':')) {
282         memcpy(timeptr + sizeof(audit_str) - 1, "0.0", 3);
283         memmove(timeptr + sizeof(audit_str) - 1 + 3, cp, strlen(cp) + 1);
284         if (!isMonotonic()) {
285             if (android::isMonotonic(now)) {
286                 LogKlog::convertMonotonicToReal(now);
287             }
288         } else {
289             if (!android::isMonotonic(now)) {
290                 LogKlog::convertRealToMonotonic(now);
291             }
292         }
293     } else if (isMonotonic()) {
294         now = log_time(CLOCK_MONOTONIC);
295     } else {
296         now = log_time(CLOCK_REALTIME);
297     }
298 
299     static const char pid_str[] = " pid=";
300     char* pidptr = strstr(str, pid_str);
301     if (pidptr && isdigit(pidptr[sizeof(pid_str) - 1])) {
302         cp = pidptr + sizeof(pid_str) - 1;
303         pid = 0;
304         while (isdigit(*cp)) {
305             pid = (pid * 10) + (*cp - '0');
306             ++cp;
307         }
308         tid = pid;
309         logbuf->wrlock();
310         uid = logbuf->pidToUid(pid);
311         logbuf->unlock();
312         memmove(pidptr, cp, strlen(cp) + 1);
313     }
314 
315     // log to events
316 
317     size_t str_len = strnlen(str, LOGGER_ENTRY_MAX_PAYLOAD);
318     if (((fdDmesg < 0) || !initialized) && !hasMetadata(str, str_len))
319         logParse(str, &bug_metadata);
320     str_len = (str_len + bug_metadata.length() <= LOGGER_ENTRY_MAX_PAYLOAD)
321                   ? str_len + bug_metadata.length()
322                   : LOGGER_ENTRY_MAX_PAYLOAD;
323     size_t message_len = str_len + sizeof(android_log_event_string_t);
324 
325     log_mask_t notify = 0;
326 
327     if (events) {  // begin scope for event buffer
328         uint32_t buffer[(message_len + sizeof(uint32_t) - 1) / sizeof(uint32_t)];
329 
330         android_log_event_string_t* event =
331             reinterpret_cast<android_log_event_string_t*>(buffer);
332         event->header.tag = htole32(AUDITD_LOG_TAG);
333         event->type = EVENT_TYPE_STRING;
334         event->length = htole32(str_len);
335         memcpy(event->data, str, str_len - bug_metadata.length());
336         memcpy(event->data + str_len - bug_metadata.length(),
337                bug_metadata.c_str(), bug_metadata.length());
338 
339         rc = logbuf->log(
340             LOG_ID_EVENTS, now, uid, pid, tid, reinterpret_cast<char*>(event),
341             (message_len <= USHRT_MAX) ? (unsigned short)message_len
342                                        : USHRT_MAX);
343         if (rc >= 0) {
344             notify |= 1 << LOG_ID_EVENTS;
345         }
346         // end scope for event buffer
347     }
348 
349     // log to main
350 
351     static const char comm_str[] = " comm=\"";
352     const char* comm = strstr(str, comm_str);
353     const char* estr = str + strlen(str);
354     const char* commfree = NULL;
355     if (comm) {
356         estr = comm;
357         comm += sizeof(comm_str) - 1;
358     } else if (pid == getpid()) {
359         pid = tid;
360         comm = "auditd";
361     } else {
362         logbuf->wrlock();
363         comm = commfree = logbuf->pidToName(pid);
364         logbuf->unlock();
365         if (!comm) {
366             comm = "unknown";
367         }
368     }
369 
370     const char* ecomm = strchr(comm, '"');
371     if (ecomm) {
372         ++ecomm;
373         str_len = ecomm - comm;
374     } else {
375         str_len = strlen(comm) + 1;
376         ecomm = "";
377     }
378     size_t prefix_len = estr - str;
379     if (prefix_len > LOGGER_ENTRY_MAX_PAYLOAD) {
380         prefix_len = LOGGER_ENTRY_MAX_PAYLOAD;
381     }
382     size_t suffix_len = strnlen(ecomm, LOGGER_ENTRY_MAX_PAYLOAD - prefix_len);
383     message_len = str_len + prefix_len + suffix_len + bug_metadata.length() + 2;
384 
385     if (main) {  // begin scope for main buffer
386         char newstr[message_len];
387 
388         *newstr = info ? ANDROID_LOG_INFO : ANDROID_LOG_WARN;
389         strlcpy(newstr + 1, comm, str_len);
390         strncpy(newstr + 1 + str_len, str, prefix_len);
391         strncpy(newstr + 1 + str_len + prefix_len, ecomm, suffix_len);
392         strncpy(newstr + 1 + str_len + prefix_len + suffix_len,
393                 bug_metadata.c_str(), bug_metadata.length());
394 
395         rc = logbuf->log(LOG_ID_MAIN, now, uid, pid, tid, newstr,
396                          (message_len <= USHRT_MAX) ? (unsigned short)message_len
397                                                     : USHRT_MAX);
398 
399         if (rc >= 0) {
400             notify |= 1 << LOG_ID_MAIN;
401         }
402         // end scope for main buffer
403     }
404 
405     free(const_cast<char*>(commfree));
406     free(str);
407 
408     if (notify) {
409         reader->notifyNewLog(notify);
410         if (rc < 0) {
411             rc = message_len;
412         }
413     }
414 
415     return rc;
416 }
417 
log(char * buf,size_t len)418 int LogAudit::log(char* buf, size_t len) {
419     char* audit = strstr(buf, " audit(");
420     if (!audit || (audit >= &buf[len])) {
421         return 0;
422     }
423 
424     *audit = '\0';
425 
426     int rc;
427     char* type = strstr(buf, "type=");
428     if (type && (type < &buf[len])) {
429         rc = logPrint("%s %s", type, audit + 1);
430     } else {
431         rc = logPrint("%s", audit + 1);
432     }
433     *audit = ' ';
434     return rc;
435 }
436 
getLogSocket()437 int LogAudit::getLogSocket() {
438     int fd = audit_open();
439     if (fd < 0) {
440         return fd;
441     }
442     if (audit_setup(fd, getpid()) < 0) {
443         audit_close(fd);
444         fd = -1;
445     }
446     return fd;
447 }
448