blob: 172a75786f698612c34e5dc2bf6194e3ebc2c3eb [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 Cherry13224722020-05-19 18:02:00 -070064LogBufferElement::LogBufferElement(LogBufferElement&& elem)
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 Cherry9787f9a2020-05-19 19:01:16 -070089 if (!IsBinary()) {
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
98 // For non-dropped messages, we get the tag from the message header itself.
Tom Cherry9787f9a2020-05-19 19:01:16 -070099 if (msg_len_ < sizeof(android_event_header_t)) {
Tom Cherrybe0f4ab2019-08-23 09:09:40 -0700100 return 0;
101 }
102
Tom Cherry9787f9a2020-05-19 19:01:16 -0700103 return reinterpret_cast<const android_event_header_t*>(msg_)->tag;
Christopher Ferris74e74f92017-08-02 17:54:27 -0700104}
105
Tom Cherry9787f9a2020-05-19 19:01:16 -0700106uint16_t LogBufferElement::SetDropped(uint16_t value) {
107 if (dropped_) {
108 return dropped_count_ = value;
Christopher Ferris74e74f92017-08-02 17:54:27 -0700109 }
Tom Cherrybe0f4ab2019-08-23 09:09:40 -0700110
Tom Cherry9787f9a2020-05-19 19:01:16 -0700111 // The tag information is saved in msg_ data, which is in a union with tag_, used after dropped_
112 // 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 -0700113 // value in its place.
Tom Cherry9787f9a2020-05-19 19:01:16 -0700114 auto old_tag = GetTag();
115 delete[] msg_;
116 msg_ = nullptr;
Tom Cherrybe0f4ab2019-08-23 09:09:40 -0700117
Tom Cherry9787f9a2020-05-19 19:01:16 -0700118 tag_ = old_tag;
119 dropped_ = true;
120 return dropped_count_ = value;
Christopher Ferris74e74f92017-08-02 17:54:27 -0700121}
122
Mark Salyzyn21fb7e02015-04-20 07:26:27 -0700123// caller must own and free character string
Mark Salyzyn501c3732017-03-10 14:31:54 -0800124char* android::tidToName(pid_t tid) {
Yi Kongc8d09dd2018-07-13 17:39:22 -0700125 char* retval = nullptr;
Mark Salyzyn21fb7e02015-04-20 07:26:27 -0700126 char buffer[256];
127 snprintf(buffer, sizeof(buffer), "/proc/%u/comm", tid);
128 int fd = open(buffer, O_RDONLY);
129 if (fd >= 0) {
130 ssize_t ret = read(fd, buffer, sizeof(buffer));
131 if (ret >= (ssize_t)sizeof(buffer)) {
132 ret = sizeof(buffer) - 1;
133 }
134 while ((ret > 0) && isspace(buffer[ret - 1])) {
135 --ret;
136 }
137 if (ret > 0) {
138 buffer[ret] = '\0';
139 retval = strdup(buffer);
140 }
141 close(fd);
Mark Salyzynab0dcf62015-03-16 12:04:09 -0700142 }
143
Mark Salyzyn21fb7e02015-04-20 07:26:27 -0700144 // if nothing for comm, check out cmdline
Mark Salyzyn501c3732017-03-10 14:31:54 -0800145 char* name = android::pidToName(tid);
Mark Salyzyn21fb7e02015-04-20 07:26:27 -0700146 if (!retval) {
147 retval = name;
Yi Kongc8d09dd2018-07-13 17:39:22 -0700148 name = nullptr;
Mark Salyzyn21fb7e02015-04-20 07:26:27 -0700149 }
150
151 // check if comm is truncated, see if cmdline has full representation
152 if (name) {
153 // impossible for retval to be NULL if name not NULL
154 size_t retval_len = strlen(retval);
155 size_t name_len = strlen(name);
156 // KISS: ToDo: Only checks prefix truncated, not suffix, or both
Mark Salyzyn501c3732017-03-10 14:31:54 -0800157 if ((retval_len < name_len) &&
158 !fastcmp<strcmp>(retval, name + name_len - retval_len)) {
Mark Salyzyn21fb7e02015-04-20 07:26:27 -0700159 free(retval);
160 retval = name;
161 } else {
162 free(name);
163 }
164 }
165 return retval;
166}
167
Tom Cherry9787f9a2020-05-19 19:01:16 -0700168// assumption: msg_ == NULL
169size_t LogBufferElement::PopulateDroppedMessage(char*& buffer, LogStatistics* stats,
Mark Salyzyn501c3732017-03-10 14:31:54 -0800170 bool lastSame) {
Mark Salyzyn047cc072015-06-04 13:35:30 -0700171 static const char tag[] = "chatty";
Mark Salyzyn21fb7e02015-04-20 07:26:27 -0700172
Mark Salyzyn501c3732017-03-10 14:31:54 -0800173 if (!__android_log_is_loggable_len(ANDROID_LOG_INFO, tag, strlen(tag),
Mark Salyzyn807e40e2016-09-22 09:56:51 -0700174 ANDROID_LOG_VERBOSE)) {
Mark Salyzyne59c4692014-10-02 13:07:05 -0700175 return 0;
176 }
177
Mark Salyzynb5b87962017-01-23 14:20:31 -0800178 static const char format_uid[] = "uid=%u%s%s %s %u line%s";
Tom Cherry9787f9a2020-05-19 19:01:16 -0700179 const char* name = stats->UidToName(uid_);
180 const char* commName = android::tidToName(tid_);
181 if (!commName && (tid_ != pid_)) {
182 commName = android::tidToName(pid_);
Mark Salyzyn21fb7e02015-04-20 07:26:27 -0700183 }
184 if (!commName) {
Tom Cherry9787f9a2020-05-19 19:01:16 -0700185 commName = stats->PidToName(pid_);
Mark Salyzyn21fb7e02015-04-20 07:26:27 -0700186 }
Mark Salyzynddda2122015-10-02 09:22:52 -0700187 if (name && name[0] && commName && (name[0] == commName[0])) {
188 size_t len = strlen(name + 1);
189 if (!strncmp(name + 1, commName + 1, len)) {
190 if (commName[len + 1] == '\0') {
Mark Salyzyn501c3732017-03-10 14:31:54 -0800191 free(const_cast<char*>(commName));
Yi Kongc8d09dd2018-07-13 17:39:22 -0700192 commName = nullptr;
Mark Salyzynddda2122015-10-02 09:22:52 -0700193 } else {
Mark Salyzyn501c3732017-03-10 14:31:54 -0800194 free(const_cast<char*>(name));
Yi Kongc8d09dd2018-07-13 17:39:22 -0700195 name = nullptr;
Mark Salyzynddda2122015-10-02 09:22:52 -0700196 }
Mark Salyzyn047cc072015-06-04 13:35:30 -0700197 }
Mark Salyzyn21fb7e02015-04-20 07:26:27 -0700198 }
199 if (name) {
Yi Kongc8d09dd2018-07-13 17:39:22 -0700200 char* buf = nullptr;
Tom Cherrya5151972020-05-15 11:39:58 -0700201 int result = asprintf(&buf, "(%s)", name);
202 if (result != -1) {
Mark Salyzyn501c3732017-03-10 14:31:54 -0800203 free(const_cast<char*>(name));
Mark Salyzyn758058f2015-08-21 16:44:30 -0700204 name = buf;
Mark Salyzyn21fb7e02015-04-20 07:26:27 -0700205 }
206 }
207 if (commName) {
Yi Kongc8d09dd2018-07-13 17:39:22 -0700208 char* buf = nullptr;
Tom Cherrya5151972020-05-15 11:39:58 -0700209 int result = asprintf(&buf, " %s", commName);
210 if (result != -1) {
Mark Salyzyn501c3732017-03-10 14:31:54 -0800211 free(const_cast<char*>(commName));
Mark Salyzyn758058f2015-08-21 16:44:30 -0700212 commName = buf;
Mark Salyzyn21fb7e02015-04-20 07:26:27 -0700213 }
214 }
215 // identical to below to calculate the buffer size required
Mark Salyzynb5b87962017-01-23 14:20:31 -0800216 const char* type = lastSame ? "identical" : "expire";
Tom Cherry9787f9a2020-05-19 19:01:16 -0700217 size_t len = snprintf(nullptr, 0, format_uid, uid_, name ? name : "", commName ? commName : "",
218 type, dropped_count(), (dropped_count() > 1) ? "s" : "");
Mark Salyzyn21fb7e02015-04-20 07:26:27 -0700219
Mark Salyzynab0dcf62015-03-16 12:04:09 -0700220 size_t hdrLen;
Tom Cherry9787f9a2020-05-19 19:01:16 -0700221 if (IsBinary()) {
Mark Salyzynab0dcf62015-03-16 12:04:09 -0700222 hdrLen = sizeof(android_log_event_string_t);
223 } else {
224 hdrLen = 1 + sizeof(tag);
225 }
226
Mark Salyzyn501c3732017-03-10 14:31:54 -0800227 buffer = static_cast<char*>(calloc(1, hdrLen + len + 1));
Mark Salyzynab0dcf62015-03-16 12:04:09 -0700228 if (!buffer) {
Mark Salyzyn501c3732017-03-10 14:31:54 -0800229 free(const_cast<char*>(name));
230 free(const_cast<char*>(commName));
Mark Salyzynab0dcf62015-03-16 12:04:09 -0700231 return 0;
232 }
233
234 size_t retval = hdrLen + len;
Tom Cherry9787f9a2020-05-19 19:01:16 -0700235 if (IsBinary()) {
Mark Salyzyn501c3732017-03-10 14:31:54 -0800236 android_log_event_string_t* event =
237 reinterpret_cast<android_log_event_string_t*>(buffer);
Mark Salyzynab0dcf62015-03-16 12:04:09 -0700238
Mark Salyzyn47684ca2016-07-15 10:19:16 -0700239 event->header.tag = htole32(CHATTY_LOG_TAG);
Mark Salyzyn758058f2015-08-21 16:44:30 -0700240 event->type = EVENT_TYPE_STRING;
241 event->length = htole32(len);
Mark Salyzynab0dcf62015-03-16 12:04:09 -0700242 } else {
243 ++retval;
244 buffer[0] = ANDROID_LOG_INFO;
245 strcpy(buffer + 1, tag);
246 }
247
Tom Cherry9787f9a2020-05-19 19:01:16 -0700248 snprintf(buffer + hdrLen, len + 1, format_uid, uid_, name ? name : "", commName ? commName : "",
249 type, dropped_count(), (dropped_count() > 1) ? "s" : "");
Mark Salyzyn501c3732017-03-10 14:31:54 -0800250 free(const_cast<char*>(name));
251 free(const_cast<char*>(commName));
Mark Salyzynab0dcf62015-03-16 12:04:09 -0700252
253 return retval;
254}
255
Tom Cherry283c9a12020-05-14 19:25:05 -0700256bool LogBufferElement::FlushTo(LogWriter* writer, LogStatistics* stats, bool lastSame) {
Tom Cherry441054a2019-10-15 16:53:11 -0700257 struct logger_entry entry = {};
Mark Salyzynab0dcf62015-03-16 12:04:09 -0700258
Tom Cherry441054a2019-10-15 16:53:11 -0700259 entry.hdr_size = sizeof(struct logger_entry);
Tom Cherry9787f9a2020-05-19 19:01:16 -0700260 entry.lid = log_id_;
261 entry.pid = pid_;
262 entry.tid = tid_;
263 entry.uid = uid_;
264 entry.sec = realtime_.tv_sec;
265 entry.nsec = realtime_.tv_nsec;
Mark Salyzyn0175b072014-02-26 09:50:16 -0800266
Yi Kongc8d09dd2018-07-13 17:39:22 -0700267 char* buffer = nullptr;
Tom Cherry283c9a12020-05-14 19:25:05 -0700268 const char* msg;
Tom Cherry9787f9a2020-05-19 19:01:16 -0700269 if (dropped_) {
270 entry.len = PopulateDroppedMessage(buffer, stats, lastSame);
Tom Cherry283c9a12020-05-14 19:25:05 -0700271 if (!entry.len) return true;
272 msg = buffer;
Mark Salyzynab0dcf62015-03-16 12:04:09 -0700273 } else {
Tom Cherry9787f9a2020-05-19 19:01:16 -0700274 msg = msg_;
275 entry.len = msg_len_;
Mark Salyzynab0dcf62015-03-16 12:04:09 -0700276 }
Mark Salyzynab0dcf62015-03-16 12:04:09 -0700277
Tom Cherry283c9a12020-05-14 19:25:05 -0700278 bool retval = writer->Write(entry, msg);
Mark Salyzynab0dcf62015-03-16 12:04:09 -0700279
Mark Salyzyn501c3732017-03-10 14:31:54 -0800280 if (buffer) free(buffer);
Mark Salyzyn0175b072014-02-26 09:50:16 -0800281
Mark Salyzynab0dcf62015-03-16 12:04:09 -0700282 return retval;
Mark Salyzyn0175b072014-02-26 09:50:16 -0800283}