1 /*
2  * Copyright (C) 2020 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 package com.android.commands.incident.sections;
18 
19 import android.util.Log;
20 import android.util.PersistedLogProto;
21 import android.util.TextLogEntry;
22 import android.util.proto.ProtoOutputStream;
23 
24 import com.android.commands.incident.ExecutionException;
25 import com.android.commands.incident.IncidentHelper;
26 import com.android.commands.incident.Section;
27 
28 import java.io.BufferedReader;
29 import java.io.File;
30 import java.io.IOException;
31 import java.io.InputStream;
32 import java.io.OutputStream;
33 import java.nio.charset.StandardCharsets;
34 import java.nio.file.Files;
35 import java.nio.file.Path;
36 import java.nio.file.Paths;
37 import java.util.ArrayList;
38 import java.util.Calendar;
39 import java.util.Comparator;
40 import java.util.GregorianCalendar;
41 import java.util.HashMap;
42 import java.util.Iterator;
43 import java.util.List;
44 import java.util.Map;
45 import java.util.regex.Matcher;
46 import java.util.regex.Pattern;
47 import java.util.stream.Stream;
48 
49 /** PersistLogSection reads persisted logs and parses them into a PersistedLogProto. */
50 public class PersistLogSection implements Section {
51     private static final String TAG = "IH_PersistLog";
52     private static final String LOG_DIR = "/data/misc/logd/";
53     // Persist log files are named logcat, logcat.001, logcat.002, logcat.003, ...
54     private static final Pattern LOG_FILE_RE = Pattern.compile("logcat(\\.\\d+)?");
55     private static final Pattern BUFFER_BEGIN_RE =
56             Pattern.compile("--------- (?:beginning of|switch to) (.*)");
57     private static final Map<String, Long> SECTION_NAME_TO_ID = new HashMap<>();
58     private static final Map<Character, Integer> LOG_PRIORITY_MAP = new HashMap<>();
59     private static final String DEFAULT_BUFFER = "main";
60 
61     static {
62         SECTION_NAME_TO_ID.put("main", PersistedLogProto.MAIN_LOGS);
63         SECTION_NAME_TO_ID.put("radio", PersistedLogProto.RADIO_LOGS);
64         SECTION_NAME_TO_ID.put("events", PersistedLogProto.EVENTS_LOGS);
65         SECTION_NAME_TO_ID.put("system", PersistedLogProto.SYSTEM_LOGS);
66         SECTION_NAME_TO_ID.put("crash", PersistedLogProto.CRASH_LOGS);
67         SECTION_NAME_TO_ID.put("kernel", PersistedLogProto.KERNEL_LOGS);
68     }
69 
70     static {
71         LOG_PRIORITY_MAP.put('V', TextLogEntry.LOG_VERBOSE);
72         LOG_PRIORITY_MAP.put('D', TextLogEntry.LOG_DEBUG);
73         LOG_PRIORITY_MAP.put('I', TextLogEntry.LOG_INFO);
74         LOG_PRIORITY_MAP.put('W', TextLogEntry.LOG_WARN);
75         LOG_PRIORITY_MAP.put('E', TextLogEntry.LOG_ERROR);
76         LOG_PRIORITY_MAP.put('F', TextLogEntry.LOG_FATAL);
77         LOG_PRIORITY_MAP.put('S', TextLogEntry.LOG_SILENT);
78     }
79 
80     /**
81      * Caches dates at 00:00:00 to epoch second elapsed conversion. There are only a few different
82      * dates in persisted logs in one device, and constructing DateTime object is relatively
83      * expensive.
84      */
85     private Map<Integer, Long> mEpochTimeCache = new HashMap<>();
86     private ProtoOutputStream mProto;
87     private long mCurrFieldId;
88     private long mMaxBytes = Long.MAX_VALUE;
89 
90     @Override
run(InputStream in, OutputStream out, List<String> args)91     public void run(InputStream in, OutputStream out, List<String> args) throws ExecutionException {
92         parseArgs(args);
93         Path logDirPath = Paths.get(LOG_DIR);
94         if (!Files.exists(logDirPath)) {
95             IncidentHelper.log(Log.WARN, TAG, "Skip dump. " + logDirPath + " does not exist.");
96             return;
97         }
98         if (!Files.isReadable(logDirPath)) {
99             IncidentHelper.log(Log.WARN, TAG, "Skip dump. " + logDirPath + " is not readable.");
100             return;
101         }
102         mProto = new ProtoOutputStream(out);
103         setCurrentSection(DEFAULT_BUFFER);
104         final Matcher logFileRe = LOG_FILE_RE.matcher("");
105         // Need to process older log files first and write logs to proto in chronological order
106         // But we want to process only the latest ones if there is a size limit
107         try (Stream<File> stream = Files.list(logDirPath).map(Path::toFile)
108                 .filter(f -> !f.isDirectory() && match(logFileRe, f.getName()) != null)
109                 .sorted(Comparator.comparingLong(File::lastModified).reversed())) {
110             Iterator<File> iter = stream.iterator();
111             List<File> filesToProcess = new ArrayList<>();
112             long sumBytes = 0;
113             while (iter.hasNext()) {
114                 File file = iter.next();
115                 sumBytes += file.length();
116                 if (sumBytes > mMaxBytes) {
117                     break;
118                 }
119                 filesToProcess.add(file);
120             }
121             IncidentHelper.log(Log.INFO, TAG, "Limit # log files to " + filesToProcess.size());
122             filesToProcess.stream()
123                     .sorted(Comparator.comparingLong(File::lastModified))
124                     .forEachOrdered(this::processFile);
125         } catch (IOException e) {
126             throw new ExecutionException(e);
127         } finally {
128             mProto.flush();
129         }
130         IncidentHelper.log(Log.DEBUG, TAG, "Bytes written: " + mProto.getBytes().length);
131     }
132 
parseArgs(List<String> args)133     private void parseArgs(List<String> args) {
134         Iterator<String> iter = args.iterator();
135         while (iter.hasNext()) {
136             String arg = iter.next();
137             if ("--limit".equals(arg) && iter.hasNext()) {
138                 String sizeStr = iter.next().toLowerCase();
139                 if (sizeStr.endsWith("mb")) {
140                     mMaxBytes = Long.parseLong(sizeStr.replace("mb", "")) * 1024 * 1024;
141                 } else if (sizeStr.endsWith("kb")) {
142                     mMaxBytes = Long.parseLong(sizeStr.replace("kb", "")) * 1024;
143                 } else {
144                     mMaxBytes = Long.parseLong(sizeStr);
145                 }
146             } else {
147                 throw new IllegalArgumentException("Unknown argument: " + arg);
148             }
149         }
150     }
151 
processFile(File file)152     private void processFile(File file) {
153         final Matcher bufferBeginRe = BUFFER_BEGIN_RE.matcher("");
154         try (BufferedReader reader = Files.newBufferedReader(file.toPath(),
155                 StandardCharsets.UTF_8)) {
156             String line;
157             Matcher m;
158             while ((line = reader.readLine()) != null) {
159                 if ((m = match(bufferBeginRe, line)) != null) {
160                     setCurrentSection(m.group(1));
161                     continue;
162                 }
163                 parseLine(line);
164             }
165         } catch (IOException e) {
166             // Non-fatal error. We can skip and still process other files.
167             IncidentHelper.log(Log.WARN, TAG, "Error reading \"" + file + "\": " + e.getMessage());
168         }
169         IncidentHelper.log(Log.DEBUG, TAG, "Finished reading " + file);
170     }
171 
setCurrentSection(String sectionName)172     private void setCurrentSection(String sectionName) {
173         Long sectionId = SECTION_NAME_TO_ID.get(sectionName);
174         if (sectionId == null) {
175             IncidentHelper.log(Log.WARN, TAG, "Section does not exist: " + sectionName);
176             sectionId = SECTION_NAME_TO_ID.get(DEFAULT_BUFFER);
177         }
178         mCurrFieldId = sectionId;
179     }
180 
181     /**
182      * Parse a log line in the following format:
183      * 01-01 15:01:47.723501  2738  2895 I Exp_TAG: example log line
184      *
185      * It does not use RegExp for performance reasons. Using this RegExp "(\\d{2})-(\\d{2})\\s
186      * (\\d{2}):(\\d{2}):(\\d{2}).(\\d{6})\\s+(\\d+)\\s+(\\d+)\\s+(.)\\s+(.*?):\\s(.*)" is twice as
187      * slow as the current approach.
188      */
parseLine(String line)189     private void parseLine(String line) {
190         long token = mProto.start(mCurrFieldId);
191         try {
192             mProto.write(TextLogEntry.SEC, getEpochSec(line));
193             // Nanosec is 15th to 20th digits of "10-01 02:57:27.710652" times 1000
194             mProto.write(TextLogEntry.NANOSEC, parseInt(line, 15, 21) * 1000L);
195 
196             int start = nextNonBlank(line, 21);
197             int end = line.indexOf(' ', start + 1);
198             mProto.write(TextLogEntry.PID, parseInt(line, start, end));
199 
200             start = nextNonBlank(line, end);
201             end = line.indexOf(' ', start + 1);
202             mProto.write(TextLogEntry.TID, parseInt(line, start, end));
203 
204             start = nextNonBlank(line, end);
205             char priority = line.charAt(start);
206             mProto.write(TextLogEntry.PRIORITY,
207                     LOG_PRIORITY_MAP.getOrDefault(priority, TextLogEntry.LOG_DEFAULT));
208 
209             start = nextNonBlank(line, start + 1);
210             end = line.indexOf(": ", start);
211             mProto.write(TextLogEntry.TAG, line.substring(start, end).trim());
212             mProto.write(TextLogEntry.LOG, line.substring(Math.min(end + 2, line.length())));
213         } catch (RuntimeException e) {
214             // Error reporting is likely piped to /dev/null. Inserting it into the proto to make
215             // it more useful.
216             mProto.write(TextLogEntry.SEC, System.currentTimeMillis() / 1000);
217             mProto.write(TextLogEntry.PRIORITY, TextLogEntry.LOG_ERROR);
218             mProto.write(TextLogEntry.TAG, TAG);
219             mProto.write(TextLogEntry.LOG,
220                     "Error parsing \"" + line + "\"" + ": " + e.getMessage());
221         }
222         mProto.end(token);
223     }
224 
225     // ============== Below are util methods to parse log lines ==============
226 
nextNonBlank(String line, int start)227     private static int nextNonBlank(String line, int start) {
228         for (int i = start; i < line.length(); i++) {
229             if (line.charAt(i) != ' ') {
230                 return i;
231             }
232         }
233         return -1;
234     }
235 
236     /**
237      * Gets the epoch second from the line string. Line starts with a fixed-length timestamp like
238      * "10-01 02:57:27.710652"
239      */
getEpochSec(String line)240     private long getEpochSec(String line) {
241         int month = getDigit(line, 0) * 10 + getDigit(line, 1);
242         int day = getDigit(line, 3) * 10 + getDigit(line, 4);
243 
244         int mmdd = month * 100 + day;
245         long epochSecBase = mEpochTimeCache.computeIfAbsent(mmdd, (key) -> {
246             final GregorianCalendar calendar = new GregorianCalendar();
247             calendar.set(Calendar.MONTH, (month + 12 - 1) % 12);
248             calendar.set(Calendar.DAY_OF_MONTH, day);
249             calendar.set(Calendar.HOUR_OF_DAY, 0);
250             calendar.set(Calendar.MINUTE, 0);
251             calendar.set(Calendar.SECOND, 0);
252             calendar.set(Calendar.MILLISECOND, 0);
253             // Date in log entries can never be in the future. If it happens, it means we are off
254             // by one year.
255             if (calendar.getTimeInMillis() > System.currentTimeMillis()) {
256                 calendar.roll(Calendar.YEAR, /*amount=*/-1);
257             }
258             return calendar.getTimeInMillis() / 1000;
259         });
260 
261         int hh = getDigit(line, 6) * 10 + getDigit(line, 7);
262         int mm = getDigit(line, 9) * 10 + getDigit(line, 10);
263         int ss = getDigit(line, 12) * 10 + getDigit(line, 13);
264         return epochSecBase + hh * 3600 + mm * 60 + ss;
265     }
266 
parseInt(String line, int start, int end)267     private static int parseInt(String line, /*inclusive*/ int start, /*exclusive*/ int end) {
268         int num = 0;
269         for (int i = start; i < end; i++) {
270             num = num * 10 + getDigit(line, i);
271         }
272         return num;
273     }
274 
getDigit(String str, int pos)275     private static int getDigit(String str, int pos) {
276         int digit = str.charAt(pos) - '0';
277         if (digit < 0 || digit > 9) {
278             throw new NumberFormatException("'" + str.charAt(pos) + "' is not a digit.");
279         }
280         return digit;
281     }
282 
match(Matcher matcher, String text)283     private static Matcher match(Matcher matcher, String text) {
284         matcher.reset(text);
285         return matcher.matches() ? matcher : null;
286     }
287 }
288