blob: 4f5cabd1d7ac2f32dc1790aedce1d235725311ba [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
Mark Salyzynee49c6a2015-06-12 14:59:42 -070033atomic_int_fast64_t LogBufferElement::sequence(1);
Mark Salyzyn0175b072014-02-26 09:50:16 -080034
Tom Cherry10d086e2019-08-21 14:16:34 -070035LogBufferElement::LogBufferElement(log_id_t log_id, log_time realtime, uid_t uid, pid_t pid,
36 pid_t tid, const char* msg, uint16_t len)
Mark Salyzyn501c3732017-03-10 14:31:54 -080037 : mUid(uid),
38 mPid(pid),
39 mTid(tid),
Tom Cherry10d086e2019-08-21 14:16:34 -070040 mSequence(sequence.fetch_add(1, memory_order_relaxed)),
Mark Salyzyn501c3732017-03-10 14:31:54 -080041 mRealTime(realtime),
42 mMsgLen(len),
Christopher Ferris74e74f92017-08-02 17:54:27 -070043 mLogId(log_id),
44 mDropped(false) {
Mark Salyzyn0175b072014-02-26 09:50:16 -080045 mMsg = new char[len];
46 memcpy(mMsg, msg, len);
47}
48
Mark Salyzyn501c3732017-03-10 14:31:54 -080049LogBufferElement::LogBufferElement(const LogBufferElement& elem)
Christopher Ferris74e74f92017-08-02 17:54:27 -070050 : mUid(elem.mUid),
Mark Salyzyn501c3732017-03-10 14:31:54 -080051 mPid(elem.mPid),
52 mTid(elem.mTid),
Tom Cherry10d086e2019-08-21 14:16:34 -070053 mSequence(elem.mSequence),
Mark Salyzyn501c3732017-03-10 14:31:54 -080054 mRealTime(elem.mRealTime),
55 mMsgLen(elem.mMsgLen),
Christopher Ferris74e74f92017-08-02 17:54:27 -070056 mLogId(elem.mLogId),
57 mDropped(elem.mDropped) {
Jintao Zhu245fb362018-12-19 22:20:12 +080058 if (mDropped) {
Tom Cherrybe0f4ab2019-08-23 09:09:40 -070059 mTag = elem.getTag();
Jintao Zhu245fb362018-12-19 22:20:12 +080060 } else {
61 mMsg = new char[mMsgLen];
62 memcpy(mMsg, elem.mMsg, mMsgLen);
63 }
Mark Salyzyna2c02222016-12-13 10:31:29 -080064}
65
Mark Salyzyn0175b072014-02-26 09:50:16 -080066LogBufferElement::~LogBufferElement() {
Tom Cherrybe0f4ab2019-08-23 09:09:40 -070067 if (!mDropped) {
68 delete[] mMsg;
69 }
Mark Salyzyn0175b072014-02-26 09:50:16 -080070}
71
Christopher Ferris74e74f92017-08-02 17:54:27 -070072uint32_t LogBufferElement::getTag() const {
Tom Cherrybe0f4ab2019-08-23 09:09:40 -070073 // Binary buffers have no tag.
74 if (!isBinary()) {
75 return 0;
76 }
77
78 // Dropped messages store the tag in place of mMsg.
79 if (mDropped) {
80 return mTag;
81 }
82
83 // For non-dropped messages, we get the tag from the message header itself.
84 if (mMsgLen < sizeof(android_event_header_t)) {
85 return 0;
86 }
87
88 return reinterpret_cast<const android_event_header_t*>(mMsg)->tag;
Christopher Ferris74e74f92017-08-02 17:54:27 -070089}
90
Chih-Hung Hsieh08d470b2018-08-13 14:22:56 -070091uint16_t LogBufferElement::setDropped(uint16_t value) {
Tom Cherrybe0f4ab2019-08-23 09:09:40 -070092 if (mDropped) {
93 return mDroppedCount = value;
Christopher Ferris74e74f92017-08-02 17:54:27 -070094 }
Tom Cherrybe0f4ab2019-08-23 09:09:40 -070095
96 // The tag information is saved in mMsg data, which is in a union with mTag, used after mDropped
97 // is set to true. Therefore we save the tag value aside, delete mMsg, then set mTag to the tag
98 // value in its place.
99 auto old_tag = getTag();
100 delete[] mMsg;
101 mMsg = nullptr;
102
103 mTag = old_tag;
Christopher Ferris74e74f92017-08-02 17:54:27 -0700104 mDropped = true;
105 return mDroppedCount = value;
106}
107
Mark Salyzyn21fb7e02015-04-20 07:26:27 -0700108// caller must own and free character string
Mark Salyzyn501c3732017-03-10 14:31:54 -0800109char* android::tidToName(pid_t tid) {
Yi Kongc8d09dd2018-07-13 17:39:22 -0700110 char* retval = nullptr;
Mark Salyzyn21fb7e02015-04-20 07:26:27 -0700111 char buffer[256];
112 snprintf(buffer, sizeof(buffer), "/proc/%u/comm", tid);
113 int fd = open(buffer, O_RDONLY);
114 if (fd >= 0) {
115 ssize_t ret = read(fd, buffer, sizeof(buffer));
116 if (ret >= (ssize_t)sizeof(buffer)) {
117 ret = sizeof(buffer) - 1;
118 }
119 while ((ret > 0) && isspace(buffer[ret - 1])) {
120 --ret;
121 }
122 if (ret > 0) {
123 buffer[ret] = '\0';
124 retval = strdup(buffer);
125 }
126 close(fd);
Mark Salyzynab0dcf62015-03-16 12:04:09 -0700127 }
128
Mark Salyzyn21fb7e02015-04-20 07:26:27 -0700129 // if nothing for comm, check out cmdline
Mark Salyzyn501c3732017-03-10 14:31:54 -0800130 char* name = android::pidToName(tid);
Mark Salyzyn21fb7e02015-04-20 07:26:27 -0700131 if (!retval) {
132 retval = name;
Yi Kongc8d09dd2018-07-13 17:39:22 -0700133 name = nullptr;
Mark Salyzyn21fb7e02015-04-20 07:26:27 -0700134 }
135
136 // check if comm is truncated, see if cmdline has full representation
137 if (name) {
138 // impossible for retval to be NULL if name not NULL
139 size_t retval_len = strlen(retval);
140 size_t name_len = strlen(name);
141 // KISS: ToDo: Only checks prefix truncated, not suffix, or both
Mark Salyzyn501c3732017-03-10 14:31:54 -0800142 if ((retval_len < name_len) &&
143 !fastcmp<strcmp>(retval, name + name_len - retval_len)) {
Mark Salyzyn21fb7e02015-04-20 07:26:27 -0700144 free(retval);
145 retval = name;
146 } else {
147 free(name);
148 }
149 }
150 return retval;
151}
152
153// assumption: mMsg == NULL
Tom Cherry64e90162020-05-07 14:44:43 -0700154size_t LogBufferElement::populateDroppedMessage(char*& buffer, LogStatistics* stats,
Mark Salyzyn501c3732017-03-10 14:31:54 -0800155 bool lastSame) {
Mark Salyzyn047cc072015-06-04 13:35:30 -0700156 static const char tag[] = "chatty";
Mark Salyzyn21fb7e02015-04-20 07:26:27 -0700157
Mark Salyzyn501c3732017-03-10 14:31:54 -0800158 if (!__android_log_is_loggable_len(ANDROID_LOG_INFO, tag, strlen(tag),
Mark Salyzyn807e40e2016-09-22 09:56:51 -0700159 ANDROID_LOG_VERBOSE)) {
Mark Salyzyne59c4692014-10-02 13:07:05 -0700160 return 0;
161 }
162
Mark Salyzynb5b87962017-01-23 14:20:31 -0800163 static const char format_uid[] = "uid=%u%s%s %s %u line%s";
Tom Cherry64e90162020-05-07 14:44:43 -0700164 const char* name = stats->UidToName(mUid);
Mark Salyzyn501c3732017-03-10 14:31:54 -0800165 const char* commName = android::tidToName(mTid);
Mark Salyzyn21fb7e02015-04-20 07:26:27 -0700166 if (!commName && (mTid != mPid)) {
Mark Salyzyn17ed6792015-04-20 13:35:15 -0700167 commName = android::tidToName(mPid);
Mark Salyzyn21fb7e02015-04-20 07:26:27 -0700168 }
169 if (!commName) {
Tom Cherry64e90162020-05-07 14:44:43 -0700170 commName = stats->PidToName(mPid);
Mark Salyzyn21fb7e02015-04-20 07:26:27 -0700171 }
Mark Salyzynddda2122015-10-02 09:22:52 -0700172 if (name && name[0] && commName && (name[0] == commName[0])) {
173 size_t len = strlen(name + 1);
174 if (!strncmp(name + 1, commName + 1, len)) {
175 if (commName[len + 1] == '\0') {
Mark Salyzyn501c3732017-03-10 14:31:54 -0800176 free(const_cast<char*>(commName));
Yi Kongc8d09dd2018-07-13 17:39:22 -0700177 commName = nullptr;
Mark Salyzynddda2122015-10-02 09:22:52 -0700178 } else {
Mark Salyzyn501c3732017-03-10 14:31:54 -0800179 free(const_cast<char*>(name));
Yi Kongc8d09dd2018-07-13 17:39:22 -0700180 name = nullptr;
Mark Salyzynddda2122015-10-02 09:22:52 -0700181 }
Mark Salyzyn047cc072015-06-04 13:35:30 -0700182 }
Mark Salyzyn21fb7e02015-04-20 07:26:27 -0700183 }
184 if (name) {
Yi Kongc8d09dd2018-07-13 17:39:22 -0700185 char* buf = nullptr;
Tom Cherrya5151972020-05-15 11:39:58 -0700186 int result = asprintf(&buf, "(%s)", name);
187 if (result != -1) {
Mark Salyzyn501c3732017-03-10 14:31:54 -0800188 free(const_cast<char*>(name));
Mark Salyzyn758058f2015-08-21 16:44:30 -0700189 name = buf;
Mark Salyzyn21fb7e02015-04-20 07:26:27 -0700190 }
191 }
192 if (commName) {
Yi Kongc8d09dd2018-07-13 17:39:22 -0700193 char* buf = nullptr;
Tom Cherrya5151972020-05-15 11:39:58 -0700194 int result = asprintf(&buf, " %s", commName);
195 if (result != -1) {
Mark Salyzyn501c3732017-03-10 14:31:54 -0800196 free(const_cast<char*>(commName));
Mark Salyzyn758058f2015-08-21 16:44:30 -0700197 commName = buf;
Mark Salyzyn21fb7e02015-04-20 07:26:27 -0700198 }
199 }
200 // identical to below to calculate the buffer size required
Mark Salyzynb5b87962017-01-23 14:20:31 -0800201 const char* type = lastSame ? "identical" : "expire";
Yi Kongc8d09dd2018-07-13 17:39:22 -0700202 size_t len = snprintf(nullptr, 0, format_uid, mUid, name ? name : "",
Christopher Ferris74e74f92017-08-02 17:54:27 -0700203 commName ? commName : "", type, getDropped(),
204 (getDropped() > 1) ? "s" : "");
Mark Salyzyn21fb7e02015-04-20 07:26:27 -0700205
Mark Salyzynab0dcf62015-03-16 12:04:09 -0700206 size_t hdrLen;
Mark Salyzyn60636fa2016-10-24 16:22:17 -0700207 if (isBinary()) {
Mark Salyzynab0dcf62015-03-16 12:04:09 -0700208 hdrLen = sizeof(android_log_event_string_t);
209 } else {
210 hdrLen = 1 + sizeof(tag);
211 }
212
Mark Salyzyn501c3732017-03-10 14:31:54 -0800213 buffer = static_cast<char*>(calloc(1, hdrLen + len + 1));
Mark Salyzynab0dcf62015-03-16 12:04:09 -0700214 if (!buffer) {
Mark Salyzyn501c3732017-03-10 14:31:54 -0800215 free(const_cast<char*>(name));
216 free(const_cast<char*>(commName));
Mark Salyzynab0dcf62015-03-16 12:04:09 -0700217 return 0;
218 }
219
220 size_t retval = hdrLen + len;
Mark Salyzyn60636fa2016-10-24 16:22:17 -0700221 if (isBinary()) {
Mark Salyzyn501c3732017-03-10 14:31:54 -0800222 android_log_event_string_t* event =
223 reinterpret_cast<android_log_event_string_t*>(buffer);
Mark Salyzynab0dcf62015-03-16 12:04:09 -0700224
Mark Salyzyn47684ca2016-07-15 10:19:16 -0700225 event->header.tag = htole32(CHATTY_LOG_TAG);
Mark Salyzyn758058f2015-08-21 16:44:30 -0700226 event->type = EVENT_TYPE_STRING;
227 event->length = htole32(len);
Mark Salyzynab0dcf62015-03-16 12:04:09 -0700228 } else {
229 ++retval;
230 buffer[0] = ANDROID_LOG_INFO;
231 strcpy(buffer + 1, tag);
232 }
233
Mark Salyzyn21fb7e02015-04-20 07:26:27 -0700234 snprintf(buffer + hdrLen, len + 1, format_uid, mUid, name ? name : "",
Christopher Ferris74e74f92017-08-02 17:54:27 -0700235 commName ? commName : "", type, getDropped(),
236 (getDropped() > 1) ? "s" : "");
Mark Salyzyn501c3732017-03-10 14:31:54 -0800237 free(const_cast<char*>(name));
238 free(const_cast<char*>(commName));
Mark Salyzynab0dcf62015-03-16 12:04:09 -0700239
240 return retval;
241}
242
Tom Cherry283c9a12020-05-14 19:25:05 -0700243bool LogBufferElement::FlushTo(LogWriter* writer, LogStatistics* stats, bool lastSame) {
Tom Cherry441054a2019-10-15 16:53:11 -0700244 struct logger_entry entry = {};
Mark Salyzynab0dcf62015-03-16 12:04:09 -0700245
Tom Cherry441054a2019-10-15 16:53:11 -0700246 entry.hdr_size = sizeof(struct logger_entry);
Mark Salyzyn0175b072014-02-26 09:50:16 -0800247 entry.lid = mLogId;
248 entry.pid = mPid;
Mark Salyzynb992d0d2014-03-20 16:09:38 -0700249 entry.tid = mTid;
Mark Salyzyn7b873652015-12-03 15:38:35 -0800250 entry.uid = mUid;
Mark Salyzyn0175b072014-02-26 09:50:16 -0800251 entry.sec = mRealTime.tv_sec;
252 entry.nsec = mRealTime.tv_nsec;
253
Yi Kongc8d09dd2018-07-13 17:39:22 -0700254 char* buffer = nullptr;
Tom Cherry283c9a12020-05-14 19:25:05 -0700255 const char* msg;
Christopher Ferris74e74f92017-08-02 17:54:27 -0700256 if (mDropped) {
Tom Cherry64e90162020-05-07 14:44:43 -0700257 entry.len = populateDroppedMessage(buffer, stats, lastSame);
Tom Cherry283c9a12020-05-14 19:25:05 -0700258 if (!entry.len) return true;
259 msg = buffer;
Mark Salyzynab0dcf62015-03-16 12:04:09 -0700260 } else {
Tom Cherry283c9a12020-05-14 19:25:05 -0700261 msg = mMsg;
Mark Salyzynab0dcf62015-03-16 12:04:09 -0700262 entry.len = mMsgLen;
Mark Salyzynab0dcf62015-03-16 12:04:09 -0700263 }
Mark Salyzynab0dcf62015-03-16 12:04:09 -0700264
Tom Cherry283c9a12020-05-14 19:25:05 -0700265 bool retval = writer->Write(entry, msg);
Mark Salyzynab0dcf62015-03-16 12:04:09 -0700266
Mark Salyzyn501c3732017-03-10 14:31:54 -0800267 if (buffer) free(buffer);
Mark Salyzyn0175b072014-02-26 09:50:16 -0800268
Mark Salyzynab0dcf62015-03-16 12:04:09 -0700269 return retval;
Mark Salyzyn0175b072014-02-26 09:50:16 -0800270}