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 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 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 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 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 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 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 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 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 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
