blob: 26affa8d47eaface3df3bafb872e77e0a87a2c27 [file] [log] [blame]
Mark Salyzyn0175b072014-02-26 09:50:16 -08001/*
2 * Copyright (C) 2012-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
Tom Cherry64e90162020-05-07 14:44:43 -070017#include "LogBufferElement.h"
18
Mark Salyzyn21fb7e02015-04-20 07:26:27 -070019#include <ctype.h>
Mark Salyzynab0dcf62015-03-16 12:04:09 -070020#include <endian.h>
Mark Salyzyn21fb7e02015-04-20 07:26:27 -070021#include <fcntl.h>
Mark Salyzyn0175b072014-02-26 09:50:16 -080022#include <stdio.h>
23#include <string.h>
24#include <time.h>
25#include <unistd.h>
26
Tom Cherryc5c6d7d2020-04-17 09:38:55 -070027#include <log/log_read.h>
Mark Salyzynab0dcf62015-03-16 12:04:09 -070028#include <private/android_logger.h>
Mark Salyzyn0175b072014-02-26 09:50:16 -080029
Tom Cherryd5b38382020-05-12 13:16:41 -070030#include "LogStatistics.h"
Mark Salyzyn2ad0bd02016-02-23 08:55:43 -080031#include "LogUtils.h"
Mark Salyzyn0175b072014-02-26 09:50:16 -080032
Tom Cherry10d086e2019-08-21 14:16:34 -070033LogBufferElement::LogBufferElement(log_id_t log_id, log_time realtime, uid_t uid, pid_t pid,
Tom Cherrya3c5ff52020-05-21 13:56:33 -070034 pid_t tid, uint64_t sequence, const char* msg, uint16_t len)
Tom Cherry9787f9a2020-05-19 19:01:16 -070035 : uid_(uid),
36 pid_(pid),
37 tid_(tid),
38 sequence_(sequence),
39 realtime_(realtime),
40 msg_len_(len),
41 log_id_(log_id),
42 dropped_(false) {
43 msg_ = new char[len];
44 memcpy(msg_, msg, len);
Mark Salyzyn0175b072014-02-26 09:50:16 -080045}
46
Mark Salyzyn501c3732017-03-10 14:31:54 -080047LogBufferElement::LogBufferElement(const LogBufferElement& elem)
Tom Cherry9787f9a2020-05-19 19:01:16 -070048 : uid_(elem.uid_),
49 pid_(elem.pid_),
50 tid_(elem.tid_),
51 sequence_(elem.sequence_),
52 realtime_(elem.realtime_),
53 msg_len_(elem.msg_len_),
54 log_id_(elem.log_id_),
55 dropped_(elem.dropped_) {
56 if (dropped_) {
57 tag_ = elem.GetTag();
Jintao Zhu245fb362018-12-19 22:20:12 +080058 } else {
Tom Cherry9787f9a2020-05-19 19:01:16 -070059 msg_ = new char[msg_len_];
60 memcpy(msg_, elem.msg_, msg_len_);
Jintao Zhu245fb362018-12-19 22:20:12 +080061 }
Mark Salyzyna2c02222016-12-13 10:31:29 -080062}
63
Tom Cherry9b4246d2020-06-17 11:40:55 -070064LogBufferElement::LogBufferElement(LogBufferElement&& elem) noexcept
Tom Cherry9787f9a2020-05-19 19:01:16 -070065 : uid_(elem.uid_),
66 pid_(elem.pid_),
67 tid_(elem.tid_),
68 sequence_(elem.sequence_),
69 realtime_(elem.realtime_),
70 msg_len_(elem.msg_len_),
71 log_id_(elem.log_id_),
72 dropped_(elem.dropped_) {
73 if (dropped_) {
74 tag_ = elem.GetTag();
Tom Cherry13224722020-05-19 18:02:00 -070075 } else {
Tom Cherry9787f9a2020-05-19 19:01:16 -070076 msg_ = elem.msg_;
77 elem.msg_ = nullptr;
Tom Cherry13224722020-05-19 18:02:00 -070078 }
79}
80
Mark Salyzyn0175b072014-02-26 09:50:16 -080081LogBufferElement::~LogBufferElement() {
Tom Cherry9787f9a2020-05-19 19:01:16 -070082 if (!dropped_) {
83 delete[] msg_;
Tom Cherrybe0f4ab2019-08-23 09:09:40 -070084 }
Mark Salyzyn0175b072014-02-26 09:50:16 -080085}
86
Tom Cherry9787f9a2020-05-19 19:01:16 -070087uint32_t LogBufferElement::GetTag() const {
Tom Cherrybe0f4ab2019-08-23 09:09:40 -070088 // Binary buffers have no tag.
Tom Cherry3dd3ec32020-06-02 15:39:21 -070089 if (!IsBinary(log_id())) {
Tom Cherrybe0f4ab2019-08-23 09:09:40 -070090 return 0;
91 }
92
Tom Cherry9787f9a2020-05-19 19:01:16 -070093 // Dropped messages store the tag in place of msg_.
94 if (dropped_) {
95 return tag_;
Tom Cherrybe0f4ab2019-08-23 09:09:40 -070096 }
97
Tom Cherry3dd3ec32020-06-02 15:39:21 -070098 return MsgToTag(msg(), msg_len());
99}
Tom Cherrybe0f4ab2019-08-23 09:09:40 -0700100
Tom Cherry3dd3ec32020-06-02 15:39:21 -0700101LogStatisticsElement LogBufferElement::ToLogStatisticsElement() const {
Tom Cherryf74503d2020-06-19 12:21:21 -0700102 // Estimate the size of this element in the parent std::list<> by adding two void*'s
103 // corresponding to the next/prev pointers and aligning to 64 bit.
104 uint16_t element_in_list_size =
105 (sizeof(*this) + 2 * sizeof(void*) + sizeof(uint64_t) - 1) & -sizeof(uint64_t);
Tom Cherry3dd3ec32020-06-02 15:39:21 -0700106 return LogStatisticsElement{
107 .uid = uid(),
108 .pid = pid(),
109 .tid = tid(),
110 .tag = GetTag(),
111 .realtime = realtime(),
112 .msg = msg(),
113 .msg_len = msg_len(),
114 .dropped_count = dropped_count(),
115 .log_id = log_id(),
Tom Cherryf74503d2020-06-19 12:21:21 -0700116 .total_len = static_cast<uint16_t>(element_in_list_size + msg_len()),
Tom Cherry3dd3ec32020-06-02 15:39:21 -0700117 };
Christopher Ferris74e74f92017-08-02 17:54:27 -0700118}
119
Tom Cherry9787f9a2020-05-19 19:01:16 -0700120uint16_t LogBufferElement::SetDropped(uint16_t value) {
121 if (dropped_) {
122 return dropped_count_ = value;
Christopher Ferris74e74f92017-08-02 17:54:27 -0700123 }
Tom Cherrybe0f4ab2019-08-23 09:09:40 -0700124
Tom Cherry9787f9a2020-05-19 19:01:16 -0700125 // The tag information is saved in msg_ data, which is in a union with tag_, used after dropped_
126 // is set to true. Therefore we save the tag value aside, delete msg_, then set tag_ to the tag
Tom Cherrybe0f4ab2019-08-23 09:09:40 -0700127 // value in its place.
Tom Cherry9787f9a2020-05-19 19:01:16 -0700128 auto old_tag = GetTag();
129 delete[] msg_;
130 msg_ = nullptr;
Tom Cherrybe0f4ab2019-08-23 09:09:40 -0700131
Tom Cherry9787f9a2020-05-19 19:01:16 -0700132 tag_ = old_tag;
133 dropped_ = true;
134 return dropped_count_ = value;
Christopher Ferris74e74f92017-08-02 17:54:27 -0700135}
136
Mark Salyzyn21fb7e02015-04-20 07:26:27 -0700137// caller must own and free character string
Mark Salyzyn501c3732017-03-10 14:31:54 -0800138char* android::tidToName(pid_t tid) {
Yi Kongc8d09dd2018-07-13 17:39:22 -0700139 char* retval = nullptr;
Mark Salyzyn21fb7e02015-04-20 07:26:27 -0700140 char buffer[256];
141 snprintf(buffer, sizeof(buffer), "/proc/%u/comm", tid);
Tom Cherry9b4246d2020-06-17 11:40:55 -0700142 int fd = open(buffer, O_RDONLY | O_CLOEXEC);
Mark Salyzyn21fb7e02015-04-20 07:26:27 -0700143 if (fd >= 0) {
144 ssize_t ret = read(fd, buffer, sizeof(buffer));
145 if (ret >= (ssize_t)sizeof(buffer)) {
146 ret = sizeof(buffer) - 1;
147 }
148 while ((ret > 0) && isspace(buffer[ret - 1])) {
149 --ret;
150 }
151 if (ret > 0) {
152 buffer[ret] = '\0';
153 retval = strdup(buffer);
154 }
155 close(fd);
Mark Salyzynab0dcf62015-03-16 12:04:09 -0700156 }
157
Mark Salyzyn21fb7e02015-04-20 07:26:27 -0700158 // if nothing for comm, check out cmdline
Mark Salyzyn501c3732017-03-10 14:31:54 -0800159 char* name = android::pidToName(tid);
Mark Salyzyn21fb7e02015-04-20 07:26:27 -0700160 if (!retval) {
161 retval = name;
Yi Kongc8d09dd2018-07-13 17:39:22 -0700162 name = nullptr;
Mark Salyzyn21fb7e02015-04-20 07:26:27 -0700163 }
164
165 // check if comm is truncated, see if cmdline has full representation
166 if (name) {
167 // impossible for retval to be NULL if name not NULL
168 size_t retval_len = strlen(retval);
169 size_t name_len = strlen(name);
170 // KISS: ToDo: Only checks prefix truncated, not suffix, or both
Mark Salyzyn501c3732017-03-10 14:31:54 -0800171 if ((retval_len < name_len) &&
172 !fastcmp<strcmp>(retval, name + name_len - retval_len)) {
Mark Salyzyn21fb7e02015-04-20 07:26:27 -0700173 free(retval);
174 retval = name;
175 } else {
176 free(name);
177 }
178 }
179 return retval;
180}
181
Tom Cherry9787f9a2020-05-19 19:01:16 -0700182// assumption: msg_ == NULL
183size_t LogBufferElement::PopulateDroppedMessage(char*& buffer, LogStatistics* stats,
Mark Salyzyn501c3732017-03-10 14:31:54 -0800184 bool lastSame) {
Mark Salyzyn047cc072015-06-04 13:35:30 -0700185 static const char tag[] = "chatty";
Mark Salyzyn21fb7e02015-04-20 07:26:27 -0700186
Mark Salyzyn501c3732017-03-10 14:31:54 -0800187 if (!__android_log_is_loggable_len(ANDROID_LOG_INFO, tag, strlen(tag),
Mark Salyzyn807e40e2016-09-22 09:56:51 -0700188 ANDROID_LOG_VERBOSE)) {
Mark Salyzyne59c4692014-10-02 13:07:05 -0700189 return 0;
190 }
191
Mark Salyzynb5b87962017-01-23 14:20:31 -0800192 static const char format_uid[] = "uid=%u%s%s %s %u line%s";
Tom Cherry9787f9a2020-05-19 19:01:16 -0700193 const char* name = stats->UidToName(uid_);
194 const char* commName = android::tidToName(tid_);
195 if (!commName && (tid_ != pid_)) {
196 commName = android::tidToName(pid_);
Mark Salyzyn21fb7e02015-04-20 07:26:27 -0700197 }
198 if (!commName) {
Tom Cherry9787f9a2020-05-19 19:01:16 -0700199 commName = stats->PidToName(pid_);
Mark Salyzyn21fb7e02015-04-20 07:26:27 -0700200 }
Mark Salyzynddda2122015-10-02 09:22:52 -0700201 if (name && name[0] && commName && (name[0] == commName[0])) {
202 size_t len = strlen(name + 1);
203 if (!strncmp(name + 1, commName + 1, len)) {
204 if (commName[len + 1] == '\0') {
Mark Salyzyn501c3732017-03-10 14:31:54 -0800205 free(const_cast<char*>(commName));
Yi Kongc8d09dd2018-07-13 17:39:22 -0700206 commName = nullptr;
Mark Salyzynddda2122015-10-02 09:22:52 -0700207 } else {
Mark Salyzyn501c3732017-03-10 14:31:54 -0800208 free(const_cast<char*>(name));
Yi Kongc8d09dd2018-07-13 17:39:22 -0700209 name = nullptr;
Mark Salyzynddda2122015-10-02 09:22:52 -0700210 }
Mark Salyzyn047cc072015-06-04 13:35:30 -0700211 }
Mark Salyzyn21fb7e02015-04-20 07:26:27 -0700212 }
213 if (name) {
Yi Kongc8d09dd2018-07-13 17:39:22 -0700214 char* buf = nullptr;
Tom Cherrya5151972020-05-15 11:39:58 -0700215 int result = asprintf(&buf, "(%s)", name);
216 if (result != -1) {
Mark Salyzyn501c3732017-03-10 14:31:54 -0800217 free(const_cast<char*>(name));
Mark Salyzyn758058f2015-08-21 16:44:30 -0700218 name = buf;
Mark Salyzyn21fb7e02015-04-20 07:26:27 -0700219 }
220 }
221 if (commName) {
Yi Kongc8d09dd2018-07-13 17:39:22 -0700222 char* buf = nullptr;
Tom Cherrya5151972020-05-15 11:39:58 -0700223 int result = asprintf(&buf, " %s", commName);
224 if (result != -1) {
Mark Salyzyn501c3732017-03-10 14:31:54 -0800225 free(const_cast<char*>(commName));
Mark Salyzyn758058f2015-08-21 16:44:30 -0700226 commName = buf;
Mark Salyzyn21fb7e02015-04-20 07:26:27 -0700227 }
228 }
229 // identical to below to calculate the buffer size required
Mark Salyzynb5b87962017-01-23 14:20:31 -0800230 const char* type = lastSame ? "identical" : "expire";
Tom Cherry9787f9a2020-05-19 19:01:16 -0700231 size_t len = snprintf(nullptr, 0, format_uid, uid_, name ? name : "", commName ? commName : "",
232 type, dropped_count(), (dropped_count() > 1) ? "s" : "");
Mark Salyzyn21fb7e02015-04-20 07:26:27 -0700233
Mark Salyzynab0dcf62015-03-16 12:04:09 -0700234 size_t hdrLen;
Tom Cherry3dd3ec32020-06-02 15:39:21 -0700235 if (IsBinary(log_id())) {
Mark Salyzynab0dcf62015-03-16 12:04:09 -0700236 hdrLen = sizeof(android_log_event_string_t);
237 } else {
238 hdrLen = 1 + sizeof(tag);
239 }
240
Mark Salyzyn501c3732017-03-10 14:31:54 -0800241 buffer = static_cast<char*>(calloc(1, hdrLen + len + 1));
Mark Salyzynab0dcf62015-03-16 12:04:09 -0700242 if (!buffer) {
Mark Salyzyn501c3732017-03-10 14:31:54 -0800243 free(const_cast<char*>(name));
244 free(const_cast<char*>(commName));
Mark Salyzynab0dcf62015-03-16 12:04:09 -0700245 return 0;
246 }
247
248 size_t retval = hdrLen + len;
Tom Cherry3dd3ec32020-06-02 15:39:21 -0700249 if (IsBinary(log_id())) {
Mark Salyzyn501c3732017-03-10 14:31:54 -0800250 android_log_event_string_t* event =
251 reinterpret_cast<android_log_event_string_t*>(buffer);
Mark Salyzynab0dcf62015-03-16 12:04:09 -0700252
Mark Salyzyn47684ca2016-07-15 10:19:16 -0700253 event->header.tag = htole32(CHATTY_LOG_TAG);
Mark Salyzyn758058f2015-08-21 16:44:30 -0700254 event->type = EVENT_TYPE_STRING;
255 event->length = htole32(len);
Mark Salyzynab0dcf62015-03-16 12:04:09 -0700256 } else {
257 ++retval;
258 buffer[0] = ANDROID_LOG_INFO;
259 strcpy(buffer + 1, tag);
260 }
261
Tom Cherry9787f9a2020-05-19 19:01:16 -0700262 snprintf(buffer + hdrLen, len + 1, format_uid, uid_, name ? name : "", commName ? commName : "",
263 type, dropped_count(), (dropped_count() > 1) ? "s" : "");
Mark Salyzyn501c3732017-03-10 14:31:54 -0800264 free(const_cast<char*>(name));
265 free(const_cast<char*>(commName));
Mark Salyzynab0dcf62015-03-16 12:04:09 -0700266
267 return retval;
268}
269
Tom Cherry283c9a12020-05-14 19:25:05 -0700270bool LogBufferElement::FlushTo(LogWriter* writer, LogStatistics* stats, bool lastSame) {
Tom Cherry441054a2019-10-15 16:53:11 -0700271 struct logger_entry entry = {};
Mark Salyzynab0dcf62015-03-16 12:04:09 -0700272
Tom Cherry441054a2019-10-15 16:53:11 -0700273 entry.hdr_size = sizeof(struct logger_entry);
Tom Cherry9787f9a2020-05-19 19:01:16 -0700274 entry.lid = log_id_;
275 entry.pid = pid_;
276 entry.tid = tid_;
277 entry.uid = uid_;
278 entry.sec = realtime_.tv_sec;
279 entry.nsec = realtime_.tv_nsec;
Mark Salyzyn0175b072014-02-26 09:50:16 -0800280
Yi Kongc8d09dd2018-07-13 17:39:22 -0700281 char* buffer = nullptr;
Tom Cherry283c9a12020-05-14 19:25:05 -0700282 const char* msg;
Tom Cherry9787f9a2020-05-19 19:01:16 -0700283 if (dropped_) {
284 entry.len = PopulateDroppedMessage(buffer, stats, lastSame);
Tom Cherry283c9a12020-05-14 19:25:05 -0700285 if (!entry.len) return true;
286 msg = buffer;
Mark Salyzynab0dcf62015-03-16 12:04:09 -0700287 } else {
Tom Cherry9787f9a2020-05-19 19:01:16 -0700288 msg = msg_;
289 entry.len = msg_len_;
Mark Salyzynab0dcf62015-03-16 12:04:09 -0700290 }
Mark Salyzynab0dcf62015-03-16 12:04:09 -0700291
Tom Cherry283c9a12020-05-14 19:25:05 -0700292 bool retval = writer->Write(entry, msg);
Mark Salyzynab0dcf62015-03-16 12:04:09 -0700293
Mark Salyzyn501c3732017-03-10 14:31:54 -0800294 if (buffer) free(buffer);
Mark Salyzyn0175b072014-02-26 09:50:16 -0800295
Mark Salyzynab0dcf62015-03-16 12:04:09 -0700296 return retval;
Mark Salyzyn0175b072014-02-26 09:50:16 -0800297}