1 /*
2  * Copyright (C) 2017 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.server.content;
18 
19 import android.accounts.Account;
20 import android.app.job.JobParameters;
21 import android.os.Build;
22 import android.os.Environment;
23 import android.os.FileUtils;
24 import android.os.Handler;
25 import android.os.Looper;
26 import android.os.Message;
27 import android.os.SystemProperties;
28 import android.text.format.DateUtils;
29 import android.util.Log;
30 import android.util.Slog;
31 
32 import com.android.internal.annotations.GuardedBy;
33 import com.android.internal.util.IntPair;
34 import com.android.server.IoThread;
35 import com.android.server.content.SyncManager.ActiveSyncContext;
36 import com.android.server.content.SyncStorageEngine.EndPoint;
37 
38 import libcore.io.IoUtils;
39 
40 import java.io.BufferedReader;
41 import java.io.File;
42 import java.io.FileReader;
43 import java.io.FileWriter;
44 import java.io.IOException;
45 import java.io.PrintWriter;
46 import java.io.Reader;
47 import java.io.Writer;
48 import java.text.SimpleDateFormat;
49 import java.util.Arrays;
50 import java.util.Date;
51 import java.util.concurrent.TimeUnit;
52 
53 /**
54  * Implements a rotating file logger for the sync manager, which is enabled only on userdebug/eng
55  * builds (unless debug.synclog is set to 1).
56  *
57  * Note this class could be used for other purposes too, but in general we don't want various
58  * system components to log to files, so it's put in a local package here.
59  */
60 public class SyncLogger {
61     private static final String TAG = "SyncLogger";
62 
63     private static SyncLogger sInstance;
64 
65     // Special UID used for logging to denote the self process.
66     public static final int CALLING_UID_SELF = -1;
67 
SyncLogger()68     SyncLogger() {
69     }
70 
71     /**
72      * @return the singleton instance.
73      */
getInstance()74     public static synchronized SyncLogger getInstance() {
75         if (sInstance == null) {
76             final String flag = SystemProperties.get("debug.synclog");
77             final boolean enable =
78                     (Build.IS_DEBUGGABLE
79                     || "1".equals(flag)
80                     || Log.isLoggable(TAG, Log.VERBOSE)) && !"0".equals(flag);
81             if (enable) {
82                 sInstance = new RotatingFileLogger();
83             } else {
84                 sInstance = new SyncLogger();
85             }
86         }
87         return sInstance;
88     }
89 
90     /**
91      * Write strings to the log file.
92      */
log(Object... message)93     public void log(Object... message) {
94     }
95 
96     /**
97      * Remove old log files.
98      */
purgeOldLogs()99     public void purgeOldLogs() {
100         // The default implementation is no-op.
101     }
102 
jobParametersToString(JobParameters params)103     public String jobParametersToString(JobParameters params) {
104         // The default implementation is no-op.
105         return "";
106     }
107 
108     /**
109      * Dump all existing log files into a given writer.
110      */
dumpAll(PrintWriter pw)111     public void dumpAll(PrintWriter pw) {
112     }
113 
114     /**
115      * @return whether log is enabled or not.
116      */
enabled()117     public boolean enabled() {
118         return false;
119     }
120 
121     /**
122      * Actual implementation which is only used on userdebug/eng builds (by default).
123      */
124     private static class RotatingFileLogger extends SyncLogger {
125         private final Object mLock = new Object();
126 
127         private final long mKeepAgeMs = TimeUnit.DAYS.toMillis(7);
128 
129         private static final SimpleDateFormat sTimestampFormat
130                 = new SimpleDateFormat("yyyy-MM-dd HH:mm:ss.SSS");
131 
132         private static final SimpleDateFormat sFilenameDateFormat
133                 = new SimpleDateFormat("yyyy-MM-dd");
134 
135         @GuardedBy("mLock")
136         private final Date mCachedDate = new Date();
137 
138         @GuardedBy("mLock")
139         private final StringBuilder mStringBuilder = new StringBuilder();
140 
141         private final File mLogPath;
142 
143         @GuardedBy("mLock")
144         private long mCurrentLogFileDayTimestamp;
145 
146         @GuardedBy("mLock")
147         private Writer mLogWriter;
148 
149         @GuardedBy("mLock")
150         private boolean mErrorShown;
151 
152         private static final boolean DO_LOGCAT = Log.isLoggable(TAG, Log.DEBUG);
153 
154         private final MyHandler mHandler;
155 
RotatingFileLogger()156         RotatingFileLogger() {
157             mLogPath = new File(Environment.getDataSystemDirectory(), "syncmanager-log");
158             mHandler = new MyHandler(IoThread.get().getLooper());
159         }
160 
161         @Override
enabled()162         public boolean enabled() {
163             return true;
164         }
165 
handleException(String message, Exception e)166         private void handleException(String message, Exception e) {
167             if (!mErrorShown) {
168                 Slog.e(TAG, message, e);
169                 mErrorShown = true;
170             }
171         }
172 
173         @Override
log(Object... message)174         public void log(Object... message) {
175             if (message == null) {
176                 return;
177             }
178             final long now = System.currentTimeMillis();
179             mHandler.log(now, message);
180         }
181 
logInner(long now, Object[] message)182         void logInner(long now, Object[] message) {
183             synchronized (mLock) {
184                 openLogLocked(now);
185                 if (mLogWriter == null) {
186                     return; // Couldn't open log file?
187                 }
188 
189                 mStringBuilder.setLength(0);
190                 mCachedDate.setTime(now);
191                 mStringBuilder.append(sTimestampFormat.format(mCachedDate));
192                 mStringBuilder.append(' ');
193 
194                 mStringBuilder.append(android.os.Process.myTid());
195                 mStringBuilder.append(' ');
196 
197                 final int messageStart = mStringBuilder.length();
198 
199                 for (Object o : message) {
200                     mStringBuilder.append(o);
201                 }
202                 mStringBuilder.append('\n');
203 
204                 try {
205                     mLogWriter.append(mStringBuilder);
206                     mLogWriter.flush();
207 
208                     // Also write on logcat.
209                     if (DO_LOGCAT) {
210                         Log.d(TAG, mStringBuilder.substring(messageStart));
211                     }
212                 } catch (IOException e) {
213                     handleException("Failed to write log", e);
214                 }
215             }
216         }
217 
218         @GuardedBy("mLock")
openLogLocked(long now)219         private void openLogLocked(long now) {
220             // If we already have a log file opened and the date has't changed, just use it.
221             final long day = now % DateUtils.DAY_IN_MILLIS;
222             if ((mLogWriter != null) && (day == mCurrentLogFileDayTimestamp)) {
223                 return;
224             }
225 
226             // Otherwise create a new log file.
227             closeCurrentLogLocked();
228 
229             mCurrentLogFileDayTimestamp = day;
230 
231             mCachedDate.setTime(now);
232             final String filename = "synclog-" + sFilenameDateFormat.format(mCachedDate) + ".log";
233             final File file = new File(mLogPath, filename);
234 
235             file.getParentFile().mkdirs();
236 
237             try {
238                 mLogWriter = new FileWriter(file, /* append= */ true);
239             } catch (IOException e) {
240                 handleException("Failed to open log file: " + file, e);
241             }
242         }
243 
244         @GuardedBy("mLock")
closeCurrentLogLocked()245         private void closeCurrentLogLocked() {
246             IoUtils.closeQuietly(mLogWriter);
247             mLogWriter = null;
248         }
249 
250         @Override
purgeOldLogs()251         public void purgeOldLogs() {
252             synchronized (mLock) {
253                 FileUtils.deleteOlderFiles(mLogPath, /* keepCount= */ 1, mKeepAgeMs);
254             }
255         }
256 
257         @Override
jobParametersToString(JobParameters params)258         public String jobParametersToString(JobParameters params) {
259             return SyncJobService.jobParametersToString(params);
260         }
261 
262         @Override
dumpAll(PrintWriter pw)263         public void dumpAll(PrintWriter pw) {
264             synchronized (mLock) {
265                 final String[] files = mLogPath.list();
266                 if (files == null || (files.length == 0)) {
267                     return;
268                 }
269                 Arrays.sort(files);
270 
271                 for (String file : files) {
272                     dumpFile(pw, new File(mLogPath, file));
273                 }
274             }
275         }
276 
dumpFile(PrintWriter pw, File file)277         private void dumpFile(PrintWriter pw, File file) {
278             Slog.w(TAG, "Dumping " + file);
279             final char[] buffer = new char[32 * 1024];
280 
281             try (Reader in = new BufferedReader(new FileReader(file))) {
282                 int read;
283                 while ((read = in.read(buffer)) >= 0) {
284                     if (read > 0) {
285                         pw.write(buffer, 0, read);
286                     }
287                 }
288             } catch (IOException e) {
289             }
290         }
291 
292         private class MyHandler extends Handler {
293             public static final int MSG_LOG_ID = 1;
294 
MyHandler(Looper looper)295             MyHandler(Looper looper) {
296                 super(looper);
297             }
298 
log(long now, Object[] message)299             public void log(long now, Object[] message) {
300                 obtainMessage(MSG_LOG_ID, IntPair.first(now), IntPair.second(now), message)
301                         .sendToTarget();
302             }
303 
304             @Override
handleMessage(Message msg)305             public void handleMessage(Message msg) {
306                 switch (msg.what) {
307                     case MSG_LOG_ID: {
308                         logInner(IntPair.of(msg.arg1, msg.arg2), (Object[]) msg.obj);
309                         break;
310                     }
311                 }
312             }
313         }
314     }
315 
logSafe(Account account)316     static String logSafe(Account account) {
317         return account == null ? "[null]" : account.toSafeString();
318     }
319 
logSafe(EndPoint endPoint)320     static String logSafe(EndPoint endPoint) {
321         return endPoint == null ? "[null]" : endPoint.toSafeString();
322     }
323 
logSafe(SyncOperation operation)324     static String logSafe(SyncOperation operation) {
325         return operation == null ? "[null]" : operation.toSafeString();
326     }
327 
logSafe(ActiveSyncContext asc)328     static String logSafe(ActiveSyncContext asc) {
329         return asc == null ? "[null]" : asc.toSafeString();
330     }
331 }
332