Mark Salyzyn | 018a96d | 2016-03-01 13:45:42 -0800 | [diff] [blame] | 1 | /* |
| 2 | * Copyright (C) 2007-2016 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 | |
Tom Cherry | 21bb36c | 2020-01-08 15:18:26 -0800 | [diff] [blame] | 17 | #include "logd_writer.h" |
| 18 | |
Mark Salyzyn | 018a96d | 2016-03-01 13:45:42 -0800 | [diff] [blame] | 19 | #include <errno.h> |
| 20 | #include <fcntl.h> |
| 21 | #include <inttypes.h> |
| 22 | #include <poll.h> |
| 23 | #include <stdarg.h> |
| 24 | #include <stdatomic.h> |
| 25 | #include <stdio.h> |
| 26 | #include <stdlib.h> |
| 27 | #include <string.h> |
Mark Salyzyn | 2ed51d7 | 2017-03-09 08:09:43 -0800 | [diff] [blame] | 28 | #include <sys/socket.h> |
Mark Salyzyn | 018a96d | 2016-03-01 13:45:42 -0800 | [diff] [blame] | 29 | #include <sys/stat.h> |
| 30 | #include <sys/types.h> |
Mark Salyzyn | 018a96d | 2016-03-01 13:45:42 -0800 | [diff] [blame] | 31 | #include <sys/un.h> |
| 32 | #include <time.h> |
| 33 | #include <unistd.h> |
| 34 | |
Mark Salyzyn | 018a96d | 2016-03-01 13:45:42 -0800 | [diff] [blame] | 35 | #include <private/android_filesystem_config.h> |
| 36 | #include <private/android_logger.h> |
| 37 | |
Mark Salyzyn | 018a96d | 2016-03-01 13:45:42 -0800 | [diff] [blame] | 38 | #include "logger.h" |
Tom Cherry | 6f6ef39 | 2019-01-16 14:17:08 -0800 | [diff] [blame] | 39 | #include "uio.h" |
Mark Salyzyn | 018a96d | 2016-03-01 13:45:42 -0800 | [diff] [blame] | 40 | |
Tom Cherry | 7acfba2 | 2020-04-24 17:15:26 -0700 | [diff] [blame^] | 41 | static atomic_int logd_socket; |
Mark Salyzyn | 018a96d | 2016-03-01 13:45:42 -0800 | [diff] [blame] | 42 | |
Tom Cherry | 7acfba2 | 2020-04-24 17:15:26 -0700 | [diff] [blame^] | 43 | // Note that it is safe to call connect() multiple times on DGRAM Unix domain sockets, so this |
| 44 | // function is used to reconnect to logd without requiring a new socket. |
| 45 | static void LogdConnect() { |
Tom Cherry | 2a6811b | 2019-12-11 12:56:01 -0800 | [diff] [blame] | 46 | sockaddr_un un = {}; |
| 47 | un.sun_family = AF_UNIX; |
| 48 | strcpy(un.sun_path, "/dev/socket/logdw"); |
Tom Cherry | 7acfba2 | 2020-04-24 17:15:26 -0700 | [diff] [blame^] | 49 | TEMP_FAILURE_RETRY(connect(logd_socket, reinterpret_cast<sockaddr*>(&un), sizeof(sockaddr_un))); |
Mark Salyzyn | 2ed51d7 | 2017-03-09 08:09:43 -0800 | [diff] [blame] | 50 | } |
| 51 | |
Tom Cherry | 7acfba2 | 2020-04-24 17:15:26 -0700 | [diff] [blame^] | 52 | // logd_socket should only be opened once. If we see that logd_socket is uninitialized, we create a |
| 53 | // new socket and attempt to exchange it into the atomic logd_socket. If the compare/exchange was |
| 54 | // successful, then that will be the socket used for the duration of the program, otherwise a |
| 55 | // different thread has already opened and written the socket to the atomic, so close the new socket |
| 56 | // and return. |
| 57 | static void GetSocket() { |
| 58 | if (logd_socket != 0) { |
Tom Cherry | 2a6811b | 2019-12-11 12:56:01 -0800 | [diff] [blame] | 59 | return; |
| 60 | } |
| 61 | |
Tom Cherry | 7acfba2 | 2020-04-24 17:15:26 -0700 | [diff] [blame^] | 62 | int new_socket = |
| 63 | TEMP_FAILURE_RETRY(socket(PF_UNIX, SOCK_DGRAM | SOCK_CLOEXEC | SOCK_NONBLOCK, 0)); |
| 64 | if (new_socket <= 0) { |
Tom Cherry | 2a6811b | 2019-12-11 12:56:01 -0800 | [diff] [blame] | 65 | return; |
Mark Salyzyn | 2ed51d7 | 2017-03-09 08:09:43 -0800 | [diff] [blame] | 66 | } |
Tom Cherry | 7acfba2 | 2020-04-24 17:15:26 -0700 | [diff] [blame^] | 67 | |
| 68 | int uninitialized_value = 0; |
| 69 | if (!logd_socket.compare_exchange_strong(uninitialized_value, new_socket)) { |
| 70 | close(new_socket); |
| 71 | return; |
| 72 | } |
| 73 | |
| 74 | LogdConnect(); |
Mark Salyzyn | 2ed51d7 | 2017-03-09 08:09:43 -0800 | [diff] [blame] | 75 | } |
| 76 | |
Tom Cherry | 7acfba2 | 2020-04-24 17:15:26 -0700 | [diff] [blame^] | 77 | // This is the one exception to the above. Zygote uses this to clean up open FD's after fork() and |
| 78 | // before specialization. It is single threaded at this point and therefore this function is |
| 79 | // explicitly not thread safe. It sets logd_socket to 0, so future logs will be safely initialized |
| 80 | // whenever they happen. |
Tom Cherry | 21bb36c | 2020-01-08 15:18:26 -0800 | [diff] [blame] | 81 | void LogdClose() { |
Tom Cherry | 2a6811b | 2019-12-11 12:56:01 -0800 | [diff] [blame] | 82 | if (logd_socket > 0) { |
| 83 | close(logd_socket); |
| 84 | } |
| 85 | logd_socket = 0; |
| 86 | } |
| 87 | |
Tom Cherry | 21bb36c | 2020-01-08 15:18:26 -0800 | [diff] [blame] | 88 | int LogdWrite(log_id_t logId, struct timespec* ts, struct iovec* vec, size_t nr) { |
Mark Salyzyn | 2ed51d7 | 2017-03-09 08:09:43 -0800 | [diff] [blame] | 89 | ssize_t ret; |
Mark Salyzyn | 2ed51d7 | 2017-03-09 08:09:43 -0800 | [diff] [blame] | 90 | static const unsigned headerLength = 1; |
| 91 | struct iovec newVec[nr + headerLength]; |
| 92 | android_log_header_t header; |
| 93 | size_t i, payloadSize; |
Tom Cherry | 71ba164 | 2019-01-10 10:37:36 -0800 | [diff] [blame] | 94 | static atomic_int dropped; |
| 95 | static atomic_int droppedSecurity; |
Mark Salyzyn | 2ed51d7 | 2017-03-09 08:09:43 -0800 | [diff] [blame] | 96 | |
Tom Cherry | 7acfba2 | 2020-04-24 17:15:26 -0700 | [diff] [blame^] | 97 | GetSocket(); |
Tom Cherry | 2a6811b | 2019-12-11 12:56:01 -0800 | [diff] [blame] | 98 | |
| 99 | if (logd_socket <= 0) { |
| 100 | return -EBADF; |
| 101 | } |
Mark Salyzyn | 018a96d | 2016-03-01 13:45:42 -0800 | [diff] [blame] | 102 | |
Mark Salyzyn | 2ed51d7 | 2017-03-09 08:09:43 -0800 | [diff] [blame] | 103 | /* logd, after initialization and priv drop */ |
Tom Cherry | b47aa2a | 2020-01-08 15:34:14 -0800 | [diff] [blame] | 104 | if (getuid() == AID_LOGD) { |
Mark Salyzyn | 018a96d | 2016-03-01 13:45:42 -0800 | [diff] [blame] | 105 | /* |
Mark Salyzyn | 2ed51d7 | 2017-03-09 08:09:43 -0800 | [diff] [blame] | 106 | * ignore log messages we send to ourself (logd). |
| 107 | * Such log messages are often generated by libraries we depend on |
| 108 | * which use standard Android logging. |
Mark Salyzyn | 018a96d | 2016-03-01 13:45:42 -0800 | [diff] [blame] | 109 | */ |
Mark Salyzyn | 2ed51d7 | 2017-03-09 08:09:43 -0800 | [diff] [blame] | 110 | return 0; |
| 111 | } |
| 112 | |
Mark Salyzyn | 2ed51d7 | 2017-03-09 08:09:43 -0800 | [diff] [blame] | 113 | header.tid = gettid(); |
| 114 | header.realtime.tv_sec = ts->tv_sec; |
| 115 | header.realtime.tv_nsec = ts->tv_nsec; |
| 116 | |
| 117 | newVec[0].iov_base = (unsigned char*)&header; |
| 118 | newVec[0].iov_len = sizeof(header); |
| 119 | |
Tom Cherry | 2a6811b | 2019-12-11 12:56:01 -0800 | [diff] [blame] | 120 | int32_t snapshot = atomic_exchange_explicit(&droppedSecurity, 0, memory_order_relaxed); |
| 121 | if (snapshot) { |
| 122 | android_log_event_int_t buffer; |
Mark Salyzyn | 2ed51d7 | 2017-03-09 08:09:43 -0800 | [diff] [blame] | 123 | |
Tom Cherry | 2a6811b | 2019-12-11 12:56:01 -0800 | [diff] [blame] | 124 | header.id = LOG_ID_SECURITY; |
| 125 | buffer.header.tag = LIBLOG_LOG_TAG; |
| 126 | buffer.payload.type = EVENT_TYPE_INT; |
| 127 | buffer.payload.data = snapshot; |
Mark Salyzyn | 2ed51d7 | 2017-03-09 08:09:43 -0800 | [diff] [blame] | 128 | |
Tom Cherry | 2a6811b | 2019-12-11 12:56:01 -0800 | [diff] [blame] | 129 | newVec[headerLength].iov_base = &buffer; |
| 130 | newVec[headerLength].iov_len = sizeof(buffer); |
Mark Salyzyn | 2ed51d7 | 2017-03-09 08:09:43 -0800 | [diff] [blame] | 131 | |
Tom Cherry | 2a6811b | 2019-12-11 12:56:01 -0800 | [diff] [blame] | 132 | ret = TEMP_FAILURE_RETRY(writev(logd_socket, newVec, 2)); |
| 133 | if (ret != (ssize_t)(sizeof(header) + sizeof(buffer))) { |
| 134 | atomic_fetch_add_explicit(&droppedSecurity, snapshot, memory_order_relaxed); |
Mark Salyzyn | 018a96d | 2016-03-01 13:45:42 -0800 | [diff] [blame] | 135 | } |
Tom Cherry | 2a6811b | 2019-12-11 12:56:01 -0800 | [diff] [blame] | 136 | } |
| 137 | snapshot = atomic_exchange_explicit(&dropped, 0, memory_order_relaxed); |
| 138 | if (snapshot && __android_log_is_loggable_len(ANDROID_LOG_INFO, "liblog", strlen("liblog"), |
| 139 | ANDROID_LOG_VERBOSE)) { |
| 140 | android_log_event_int_t buffer; |
Mark Salyzyn | 2ed51d7 | 2017-03-09 08:09:43 -0800 | [diff] [blame] | 141 | |
Tom Cherry | 2a6811b | 2019-12-11 12:56:01 -0800 | [diff] [blame] | 142 | header.id = LOG_ID_EVENTS; |
| 143 | buffer.header.tag = LIBLOG_LOG_TAG; |
| 144 | buffer.payload.type = EVENT_TYPE_INT; |
| 145 | buffer.payload.data = snapshot; |
Mark Salyzyn | 2ed51d7 | 2017-03-09 08:09:43 -0800 | [diff] [blame] | 146 | |
Tom Cherry | 2a6811b | 2019-12-11 12:56:01 -0800 | [diff] [blame] | 147 | newVec[headerLength].iov_base = &buffer; |
| 148 | newVec[headerLength].iov_len = sizeof(buffer); |
Mark Salyzyn | 2ed51d7 | 2017-03-09 08:09:43 -0800 | [diff] [blame] | 149 | |
Tom Cherry | 2a6811b | 2019-12-11 12:56:01 -0800 | [diff] [blame] | 150 | ret = TEMP_FAILURE_RETRY(writev(logd_socket, newVec, 2)); |
| 151 | if (ret != (ssize_t)(sizeof(header) + sizeof(buffer))) { |
| 152 | atomic_fetch_add_explicit(&dropped, snapshot, memory_order_relaxed); |
Mark Salyzyn | 2ed51d7 | 2017-03-09 08:09:43 -0800 | [diff] [blame] | 153 | } |
| 154 | } |
| 155 | |
| 156 | header.id = logId; |
| 157 | |
| 158 | for (payloadSize = 0, i = headerLength; i < nr + headerLength; i++) { |
| 159 | newVec[i].iov_base = vec[i - headerLength].iov_base; |
| 160 | payloadSize += newVec[i].iov_len = vec[i - headerLength].iov_len; |
| 161 | |
| 162 | if (payloadSize > LOGGER_ENTRY_MAX_PAYLOAD) { |
| 163 | newVec[i].iov_len -= payloadSize - LOGGER_ENTRY_MAX_PAYLOAD; |
| 164 | if (newVec[i].iov_len) { |
| 165 | ++i; |
| 166 | } |
| 167 | break; |
| 168 | } |
| 169 | } |
| 170 | |
Tom Cherry | 2a6811b | 2019-12-11 12:56:01 -0800 | [diff] [blame] | 171 | // The write below could be lost, but will never block. |
| 172 | // EAGAIN occurs if logd is overloaded, other errors indicate that something went wrong with |
| 173 | // the connection, so we reset it and try again. |
| 174 | ret = TEMP_FAILURE_RETRY(writev(logd_socket, newVec, i)); |
| 175 | if (ret < 0 && errno != EAGAIN) { |
Tom Cherry | 7acfba2 | 2020-04-24 17:15:26 -0700 | [diff] [blame^] | 176 | LogdConnect(); |
Tom Cherry | 2a6811b | 2019-12-11 12:56:01 -0800 | [diff] [blame] | 177 | |
| 178 | ret = TEMP_FAILURE_RETRY(writev(logd_socket, newVec, i)); |
Mark Salyzyn | 2ed51d7 | 2017-03-09 08:09:43 -0800 | [diff] [blame] | 179 | } |
Mark Salyzyn | 65e1e62 | 2017-01-03 13:28:18 -0800 | [diff] [blame] | 180 | |
Tom Cherry | 2a6811b | 2019-12-11 12:56:01 -0800 | [diff] [blame] | 181 | if (ret < 0) { |
| 182 | ret = -errno; |
Mark Salyzyn | 2ed51d7 | 2017-03-09 08:09:43 -0800 | [diff] [blame] | 183 | } |
Mark Salyzyn | 018a96d | 2016-03-01 13:45:42 -0800 | [diff] [blame] | 184 | |
Mark Salyzyn | 2ed51d7 | 2017-03-09 08:09:43 -0800 | [diff] [blame] | 185 | if (ret > (ssize_t)sizeof(header)) { |
| 186 | ret -= sizeof(header); |
Tom Cherry | 2a6811b | 2019-12-11 12:56:01 -0800 | [diff] [blame] | 187 | } else if (ret < 0) { |
Mark Salyzyn | 2ed51d7 | 2017-03-09 08:09:43 -0800 | [diff] [blame] | 188 | atomic_fetch_add_explicit(&dropped, 1, memory_order_relaxed); |
| 189 | if (logId == LOG_ID_SECURITY) { |
| 190 | atomic_fetch_add_explicit(&droppedSecurity, 1, memory_order_relaxed); |
Mark Salyzyn | 018a96d | 2016-03-01 13:45:42 -0800 | [diff] [blame] | 191 | } |
Mark Salyzyn | 2ed51d7 | 2017-03-09 08:09:43 -0800 | [diff] [blame] | 192 | } |
Mark Salyzyn | 018a96d | 2016-03-01 13:45:42 -0800 | [diff] [blame] | 193 | |
Mark Salyzyn | 2ed51d7 | 2017-03-09 08:09:43 -0800 | [diff] [blame] | 194 | return ret; |
Mark Salyzyn | 018a96d | 2016-03-01 13:45:42 -0800 | [diff] [blame] | 195 | } |