1 /* 2 * Copyright (C) 2010 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.wifi; 18 19 import android.annotation.NonNull; 20 import android.annotation.SuppressLint; 21 import android.content.Context; 22 import android.content.Intent; 23 import android.content.pm.PackageManager; 24 import android.os.BugreportManager; 25 import android.os.BugreportParams; 26 import android.os.Handler; 27 import android.os.Looper; 28 import android.util.ArraySet; 29 import android.util.Base64; 30 import android.util.Log; 31 import android.util.SparseLongArray; 32 33 import com.android.internal.annotations.VisibleForTesting; 34 import com.android.server.wifi.util.ByteArrayRingBuffer; 35 import com.android.server.wifi.util.StringUtil; 36 import com.android.wifi.resources.R; 37 38 import java.io.BufferedReader; 39 import java.io.ByteArrayOutputStream; 40 import java.io.FileDescriptor; 41 import java.io.IOException; 42 import java.io.InputStreamReader; 43 import java.io.PrintWriter; 44 import java.nio.charset.Charset; 45 import java.util.ArrayList; 46 import java.util.Arrays; 47 import java.util.Calendar; 48 import java.util.Comparator; 49 import java.util.HashMap; 50 import java.util.List; 51 import java.util.Set; 52 import java.util.concurrent.TimeUnit; 53 import java.util.stream.Collectors; 54 import java.util.zip.Deflater; 55 56 /** 57 * Tracks various logs for framework. 58 */ 59 public class WifiDiagnostics { 60 /** 61 * Thread-safety: 62 * 1) Most non-private methods are |synchronized| with the exception of 63 * {@link #captureBugReportData(int)} and {@link #triggerBugReportDataCapture(int)}, and 64 * a few others. See those methods' documentation. 65 * 2) Callbacks into WifiDiagnostics use non-private (and hence, synchronized) methods. 66 * See, e.g, onRingBufferData(), onWifiAlert(). 67 */ 68 69 private static final String TAG = "WifiDiags"; 70 private static final boolean DBG = false; 71 72 public static final byte CONNECTION_EVENT_STARTED = 0; 73 public static final byte CONNECTION_EVENT_SUCCEEDED = 1; 74 public static final byte CONNECTION_EVENT_FAILED = 2; 75 public static final byte CONNECTION_EVENT_TIMEOUT = 3; 76 77 /** log level flags; keep these consistent with wifi_logger.h */ 78 79 /** No logs whatsoever */ 80 public static final int VERBOSE_NO_LOG = 0; 81 /** No logs whatsoever */ 82 public static final int VERBOSE_NORMAL_LOG = 1; 83 /** Be careful since this one can affect performance and power */ 84 public static final int VERBOSE_LOG_WITH_WAKEUP = 2; 85 /** Be careful since this one can affect performance and power and memory */ 86 public static final int VERBOSE_DETAILED_LOG_WITH_WAKEUP = 3; 87 88 /** ring buffer flags; keep these consistent with wifi_logger.h */ 89 public static final int RING_BUFFER_FLAG_HAS_BINARY_ENTRIES = 0x00000001; 90 public static final int RING_BUFFER_FLAG_HAS_ASCII_ENTRIES = 0x00000002; 91 public static final int RING_BUFFER_FLAG_HAS_PER_PACKET_ENTRIES = 0x00000004; 92 93 /** various reason codes */ 94 public static final int REPORT_REASON_NONE = 0; 95 public static final int REPORT_REASON_ASSOC_FAILURE = 1; 96 public static final int REPORT_REASON_AUTH_FAILURE = 2; 97 public static final int REPORT_REASON_AUTOROAM_FAILURE = 3; 98 public static final int REPORT_REASON_DHCP_FAILURE = 4; 99 public static final int REPORT_REASON_UNEXPECTED_DISCONNECT = 5; 100 public static final int REPORT_REASON_SCAN_FAILURE = 6; 101 public static final int REPORT_REASON_USER_ACTION = 7; 102 public static final int REPORT_REASON_WIFINATIVE_FAILURE = 8; 103 public static final int REPORT_REASON_REACHABILITY_LOST = 9; 104 public static final int REPORT_REASON_FATAL_FW_ALERT = 10; 105 public static final int REPORT_REASON_REACHABILITY_FAILURE = 11; 106 107 /** number of bug reports to hold */ 108 public static final int MAX_BUG_REPORTS = 4; 109 110 /** number of alerts to hold */ 111 public static final int MAX_ALERT_REPORTS = 1; 112 113 /** minimum wakeup interval for each of the log levels */ 114 private static final int MinWakeupIntervals[] = new int[] { 0, 3600, 60, 10 }; 115 /** minimum buffer size for each of the log levels */ 116 private static final int MinBufferSizes[] = new int[] { 0, 16384, 16384, 65536 }; 117 118 /** Map from dump reason to elapsed time millis */ 119 private final SparseLongArray mLastDumpTime = new SparseLongArray(); 120 121 /** Minimum dump period with same error code */ 122 public static final long MIN_DUMP_TIME_WINDOW_MILLIS = 10 * 60 * 1000; // 10 mins 123 124 // Timeout for logcat process termination 125 private static final long LOGCAT_PROC_TIMEOUT_MILLIS = 50; 126 // Timeout for logcat read from input/error stream each. 127 @VisibleForTesting 128 public static final long LOGCAT_READ_TIMEOUT_MILLIS = 50; 129 130 private long mLastBugReportTime; 131 132 @VisibleForTesting public static final String FIRMWARE_DUMP_SECTION_HEADER = 133 "FW Memory dump"; 134 @VisibleForTesting public static final String DRIVER_DUMP_SECTION_HEADER = 135 "Driver state dump"; 136 137 private final WifiNative mWifiNative; 138 private final Context mContext; 139 private final BuildProperties mBuildProperties; 140 private final WifiLog mLog; 141 private final LastMileLogger mLastMileLogger; 142 private final Runtime mJavaRuntime; 143 private final WifiMetrics mWifiMetrics; 144 private final WifiInjector mWifiInjector; 145 private final Clock mClock; 146 private final Handler mWorkerThreadHandler; 147 148 private int mHalLogLevel = VERBOSE_NO_LOG; 149 private boolean mIsLoggingEventHandlerRegistered; 150 private WifiNative.RingBufferStatus[] mRingBuffers; 151 private WifiNative.RingBufferStatus mPerPacketRingBuffer; 152 private String mFirmwareVersion; 153 private String mDriverVersion; 154 private int mSupportedFeatureSet; 155 private int mMaxRingBufferSizeBytes; 156 157 /** Interfaces started logging */ 158 private final Set<String> mActiveInterfaces = new ArraySet<>(); 159 private String mLatestIfaceLogged = ""; 160 WifiDiagnostics( Context context, WifiInjector wifiInjector, WifiNative wifiNative, BuildProperties buildProperties, LastMileLogger lastMileLogger, Clock clock, Looper workerLooper)161 public WifiDiagnostics( 162 Context context, WifiInjector wifiInjector, 163 WifiNative wifiNative, BuildProperties buildProperties, 164 LastMileLogger lastMileLogger, Clock clock, Looper workerLooper) { 165 mContext = context; 166 mWifiNative = wifiNative; 167 mBuildProperties = buildProperties; 168 mIsLoggingEventHandlerRegistered = false; 169 mLog = wifiInjector.makeLog(TAG); 170 mLastMileLogger = lastMileLogger; 171 mJavaRuntime = wifiInjector.getJavaRuntime(); 172 mWifiMetrics = wifiInjector.getWifiMetrics(); 173 mWifiInjector = wifiInjector; 174 mClock = clock; 175 mWorkerThreadHandler = new Handler(workerLooper); 176 } 177 178 /** 179 * Start wifi HAL dependent logging features. 180 * This method should be called only after the interface has 181 * been set up. 182 * 183 * @param ifaceName the interface requesting to start logging. 184 */ startLogging(@onNull String ifaceName)185 public synchronized void startLogging(@NonNull String ifaceName) { 186 if (mActiveInterfaces.contains(ifaceName)) { 187 Log.w(TAG, "Interface: " + ifaceName + " had already started logging"); 188 return; 189 } 190 if (mActiveInterfaces.isEmpty()) { 191 mFirmwareVersion = mWifiNative.getFirmwareVersion(); 192 mDriverVersion = mWifiNative.getDriverVersion(); 193 mSupportedFeatureSet = mWifiNative.getSupportedLoggerFeatureSet(); 194 195 if (!mIsLoggingEventHandlerRegistered) { 196 mIsLoggingEventHandlerRegistered = mWifiNative.setLoggingEventHandler(mHandler); 197 } 198 199 startLoggingRingBuffers(); 200 } 201 202 mActiveInterfaces.add(ifaceName); 203 mLatestIfaceLogged = ifaceName; 204 205 Log.d(TAG, "startLogging() iface list is " + mActiveInterfaces 206 + " after adding " + ifaceName); 207 } 208 startPacketLog()209 public synchronized void startPacketLog() { 210 if (mPerPacketRingBuffer != null) { 211 startLoggingRingBuffer(mPerPacketRingBuffer); 212 } else { 213 if (DBG) mLog.tC("There is no per packet ring buffer"); 214 } 215 } 216 stopPacketLog()217 public synchronized void stopPacketLog() { 218 if (mPerPacketRingBuffer != null) { 219 stopLoggingRingBuffer(mPerPacketRingBuffer); 220 } else { 221 if (DBG) mLog.tC("There is no per packet ring buffer"); 222 } 223 } 224 225 /** 226 * Stop wifi HAL dependent logging features. 227 * This method should be called before the interface has been 228 * torn down. 229 * 230 * @param ifaceName the interface requesting to stop logging. 231 */ stopLogging(@onNull String ifaceName)232 public synchronized void stopLogging(@NonNull String ifaceName) { 233 if (!mActiveInterfaces.contains(ifaceName)) { 234 Log.w(TAG, "ifaceName: " + ifaceName + " is not in the start log user list"); 235 return; 236 } 237 238 mActiveInterfaces.remove(ifaceName); 239 240 Log.d(TAG, "stopLogging() iface list is " + mActiveInterfaces 241 + " after removing " + ifaceName); 242 243 if (!mActiveInterfaces.isEmpty()) { 244 return; 245 } 246 if (mHalLogLevel != VERBOSE_NO_LOG) { 247 stopLoggingAllBuffers(); 248 mRingBuffers = null; 249 } 250 if (mIsLoggingEventHandlerRegistered) { 251 if (!mWifiNative.resetLogHandler()) { 252 mLog.wC("Fail to reset log handler"); 253 } else { 254 if (DBG) mLog.tC("Reset log handler"); 255 } 256 // Clear mIsLoggingEventHandlerRegistered even if resetLogHandler() failed, because 257 // the log handler is in an indeterminate state. 258 mIsLoggingEventHandlerRegistered = false; 259 } 260 } 261 262 /** 263 * Inform the diagnostics module of a connection event. 264 * @param event The type of connection event (see CONNECTION_EVENT_* constants) 265 */ reportConnectionEvent(byte event, ClientModeManager clientModeManager)266 public synchronized void reportConnectionEvent(byte event, 267 ClientModeManager clientModeManager) { 268 mLastMileLogger.reportConnectionEvent(clientModeManager.getInterfaceName(), event); 269 if (event == CONNECTION_EVENT_FAILED || event == CONNECTION_EVENT_TIMEOUT) { 270 mPacketFatesForLastFailure = new PacketFates(clientModeManager); 271 } 272 } 273 274 /** 275 * Synchronously capture bug report data. 276 * 277 * Note: this method is not marked as synchronized, but it is synchronized internally. 278 * getLogcat*() methods are very slow, so do not synchronize these calls (they are thread safe, 279 * do not need to be synchronized). 280 */ captureBugReportData(int reason)281 public void captureBugReportData(int reason) { 282 final boolean verbose; 283 synchronized (this) { 284 verbose = isHalVerboseLoggingEnabled(); 285 } 286 BugReport report = captureBugreport(reason, verbose); 287 synchronized (this) { 288 mLastBugReports.addLast(report); 289 flushDump(reason); 290 } 291 } 292 293 /** 294 * Asynchronously capture bug report data. 295 * 296 * Not synchronized because no work is performed on the calling thread. 297 */ triggerBugReportDataCapture(int reason)298 public void triggerBugReportDataCapture(int reason) { 299 mWorkerThreadHandler.post(() -> { 300 captureBugReportData(reason); 301 }); 302 } 303 triggerAlertDataCapture(int errorCode, byte[] alertData)304 private void triggerAlertDataCapture(int errorCode, byte[] alertData) { 305 mWorkerThreadHandler.post(() -> { 306 final boolean verbose; 307 synchronized (this) { 308 verbose = isHalVerboseLoggingEnabled(); 309 } 310 // This is very slow, don't put this inside `synchronized(this)`! 311 BugReport report = captureBugreport(errorCode, verbose); 312 synchronized (this) { 313 report.alertData = alertData; 314 mLastAlerts.addLast(report); 315 316 /* Flush HAL ring buffer when detecting data stall */ 317 if (Arrays.stream(mContext.getResources().getIntArray( 318 R.array.config_wifi_fatal_firmware_alert_error_code_list)) 319 .boxed().collect(Collectors.toList()).contains(errorCode)) { 320 flushDump(REPORT_REASON_FATAL_FW_ALERT); 321 } 322 } 323 }); 324 } 325 dump(FileDescriptor fd, PrintWriter pw, String[] args)326 public synchronized void dump(FileDescriptor fd, PrintWriter pw, String[] args) { 327 pw.println("Chipset information :-----------------------------------------------"); 328 pw.println("FW Version is: " + mFirmwareVersion); 329 pw.println("Driver Version is: " + mDriverVersion); 330 pw.println("Supported Feature set: " + mSupportedFeatureSet); 331 332 for (int i = 0; i < mLastAlerts.size(); i++) { 333 pw.println("--------------------------------------------------------------------"); 334 pw.println("Alert dump " + i); 335 pw.print(mLastAlerts.get(i)); 336 pw.println("--------------------------------------------------------------------"); 337 } 338 339 for (int i = 0; i < mLastBugReports.size(); i++) { 340 pw.println("--------------------------------------------------------------------"); 341 pw.println("Bug dump " + i); 342 pw.print(mLastBugReports.get(i)); 343 pw.println("--------------------------------------------------------------------"); 344 } 345 346 pw.println("Last Flush Time: " + mLastDumpTime.toString()); 347 pw.println("--------------------------------------------------------------------"); 348 349 dumpPacketFates(pw); 350 mLastMileLogger.dump(pw); 351 352 pw.println("--------------------------------------------------------------------"); 353 } 354 355 // TODO(b/193460475): BugReportManager changes from SystemApi to PublicApi, not a new API 356 @SuppressLint("NewApi") takeBugReportThroughBugreportManager(String bugTitle, String bugDetail)357 private void takeBugReportThroughBugreportManager(String bugTitle, String bugDetail) { 358 BugreportManager bugreportManager = mContext.getSystemService(BugreportManager.class); 359 BugreportParams params = new BugreportParams(BugreportParams.BUGREPORT_MODE_FULL); 360 try { 361 bugreportManager.requestBugreport(params, bugTitle, bugDetail); 362 mLastBugReportTime = mClock.getWallClockMillis(); 363 } catch (RuntimeException e) { 364 mLog.err("error taking bugreport: %").c(e.getClass().getName()).flush(); 365 } 366 } 367 368 /* private methods and data */ 369 class BugReport { 370 long systemTimeMs; 371 long kernelTimeNanos; 372 int errorCode; 373 HashMap<String, byte[][]> ringBuffers = new HashMap(); 374 byte[] fwMemoryDump; 375 byte[] mDriverStateDump; 376 byte[] alertData; 377 ArrayList<String> kernelLogLines; 378 ArrayList<String> logcatLines; 379 clearVerboseLogs()380 void clearVerboseLogs() { 381 fwMemoryDump = null; 382 mDriverStateDump = null; 383 } 384 toString()385 public String toString() { 386 StringBuilder builder = new StringBuilder(); 387 388 Calendar c = Calendar.getInstance(); 389 c.setTimeInMillis(systemTimeMs); 390 builder.append("system time = ") 391 .append(StringUtil.calendarToString(c)).append("\n"); 392 393 long kernelTimeMs = kernelTimeNanos/(1000*1000); 394 builder.append("kernel time = ").append(kernelTimeMs/1000).append(".").append 395 (kernelTimeMs%1000).append("\n"); 396 397 if (alertData == null) 398 builder.append("reason = ").append(errorCode).append("\n"); 399 else { 400 builder.append("errorCode = ").append(errorCode); 401 builder.append("data \n"); 402 builder.append(compressToBase64(alertData)).append("\n"); 403 } 404 405 if (kernelLogLines != null) { 406 builder.append("kernel log: \n"); 407 for (int i = 0; i < kernelLogLines.size(); i++) { 408 builder.append(kernelLogLines.get(i)).append("\n"); 409 } 410 builder.append("\n"); 411 } 412 413 if (logcatLines != null) { 414 builder.append("system log: \n"); 415 for (int i = 0; i < logcatLines.size(); i++) { 416 builder.append(logcatLines.get(i)).append("\n"); 417 } 418 builder.append("\n"); 419 } 420 421 for (HashMap.Entry<String, byte[][]> e : ringBuffers.entrySet()) { 422 String ringName = e.getKey(); 423 byte[][] buffers = e.getValue(); 424 builder.append("ring-buffer = ").append(ringName).append("\n"); 425 426 int size = 0; 427 for (int i = 0; i < buffers.length; i++) { 428 size += buffers[i].length; 429 } 430 431 byte[] buffer = new byte[size]; 432 int index = 0; 433 for (int i = 0; i < buffers.length; i++) { 434 System.arraycopy(buffers[i], 0, buffer, index, buffers[i].length); 435 index += buffers[i].length; 436 } 437 438 builder.append(compressToBase64(buffer)); 439 builder.append("\n"); 440 } 441 442 if (fwMemoryDump != null) { 443 builder.append(FIRMWARE_DUMP_SECTION_HEADER); 444 builder.append("\n"); 445 builder.append(compressToBase64(fwMemoryDump)); 446 builder.append("\n"); 447 } 448 449 if (mDriverStateDump != null) { 450 builder.append(DRIVER_DUMP_SECTION_HEADER); 451 if (StringUtil.isAsciiPrintable(mDriverStateDump)) { 452 builder.append(" (ascii)\n"); 453 builder.append(new String(mDriverStateDump, Charset.forName("US-ASCII"))); 454 builder.append("\n"); 455 } else { 456 builder.append(" (base64)\n"); 457 builder.append(compressToBase64(mDriverStateDump)); 458 } 459 } 460 461 return builder.toString(); 462 } 463 } 464 465 static class LimitedCircularArray<E> { 466 private ArrayList<E> mArrayList; 467 private int mMax; LimitedCircularArray(int max)468 LimitedCircularArray(int max) { 469 mArrayList = new ArrayList<E>(max); 470 mMax = max; 471 } 472 addLast(E e)473 public final void addLast(E e) { 474 if (mArrayList.size() >= mMax) 475 mArrayList.remove(0); 476 mArrayList.add(e); 477 } 478 size()479 public final int size() { 480 return mArrayList.size(); 481 } 482 get(int i)483 public final E get(int i) { 484 return mArrayList.get(i); 485 } 486 } 487 488 private final LimitedCircularArray<BugReport> mLastAlerts = 489 new LimitedCircularArray<BugReport>(MAX_ALERT_REPORTS); 490 private final LimitedCircularArray<BugReport> mLastBugReports = 491 new LimitedCircularArray<BugReport>(MAX_BUG_REPORTS); 492 private final HashMap<String, ByteArrayRingBuffer> mRingBufferData = new HashMap(); 493 494 private final WifiNative.WifiLoggerEventHandler mHandler = 495 new WifiNative.WifiLoggerEventHandler() { 496 @Override 497 public void onRingBufferData(WifiNative.RingBufferStatus status, byte[] buffer) { 498 WifiDiagnostics.this.onRingBufferData(status, buffer); 499 } 500 501 @Override 502 public void onWifiAlert(int errorCode, byte[] buffer) { 503 WifiDiagnostics.this.onWifiAlert(errorCode, buffer); 504 } 505 }; 506 onRingBufferData(WifiNative.RingBufferStatus status, byte[] buffer)507 synchronized void onRingBufferData(WifiNative.RingBufferStatus status, byte[] buffer) { 508 ByteArrayRingBuffer ring = mRingBufferData.get(status.name); 509 if (ring != null) { 510 ring.appendBuffer(buffer); 511 } 512 } 513 onWifiAlert(int errorCode, @NonNull byte[] buffer)514 synchronized void onWifiAlert(int errorCode, @NonNull byte[] buffer) { 515 triggerAlertDataCapture(errorCode, buffer); 516 // TODO b/166309727 This currently assumes that the firmware alert comes from latest 517 // interface that started logging, as the callback does not tell us which interface 518 // caused the alert. 519 mWifiMetrics.logFirmwareAlert(mLatestIfaceLogged, errorCode); 520 mWifiInjector.getWifiScoreCard().noteFirmwareAlert(errorCode); 521 } 522 523 /** 524 * Enables or disables verbose logging 525 * 526 * @param verbose - with the obvious interpretation 527 */ enableVerboseLogging(boolean verboseEnabled, boolean halVerboseEnabled)528 public synchronized void enableVerboseLogging(boolean verboseEnabled, 529 boolean halVerboseEnabled) { 530 final int ringBufferByteLimitSmall = mContext.getResources().getInteger( 531 R.integer.config_wifi_logger_ring_buffer_default_size_limit_kb) * 1024; 532 final int ringBufferByteLimitLarge = mContext.getResources().getInteger( 533 R.integer.config_wifi_logger_ring_buffer_verbose_size_limit_kb) * 1024; 534 if (halVerboseEnabled) { 535 mHalLogLevel = VERBOSE_LOG_WITH_WAKEUP; 536 mMaxRingBufferSizeBytes = ringBufferByteLimitLarge; 537 } else { 538 mHalLogLevel = VERBOSE_NORMAL_LOG; 539 mMaxRingBufferSizeBytes = enableVerboseLoggingForDogfood() 540 ? ringBufferByteLimitLarge : ringBufferByteLimitSmall; 541 } 542 543 if (!mActiveInterfaces.isEmpty()) { 544 mLog.wC("verbosity changed: restart logging"); 545 startLoggingRingBuffers(); 546 } 547 } 548 isHalVerboseLoggingEnabled()549 private boolean isHalVerboseLoggingEnabled() { 550 return mHalLogLevel > VERBOSE_NORMAL_LOG; 551 } 552 clearVerboseLogs()553 private void clearVerboseLogs() { 554 for (int i = 0; i < mLastAlerts.size(); i++) { 555 mLastAlerts.get(i).clearVerboseLogs(); 556 } 557 558 for (int i = 0; i < mLastBugReports.size(); i++) { 559 mLastBugReports.get(i).clearVerboseLogs(); 560 } 561 } 562 fetchRingBuffers()563 private boolean fetchRingBuffers() { 564 if (mRingBuffers != null) return true; 565 566 mRingBuffers = mWifiNative.getRingBufferStatus(); 567 if (mRingBuffers != null) { 568 for (WifiNative.RingBufferStatus buffer : mRingBuffers) { 569 if (DBG) mLog.trace("RingBufferStatus is: %").c(buffer.name).flush(); 570 if (mRingBufferData.containsKey(buffer.name) == false) { 571 mRingBufferData.put(buffer.name, 572 new ByteArrayRingBuffer(mMaxRingBufferSizeBytes)); 573 } 574 if ((buffer.flag & RING_BUFFER_FLAG_HAS_PER_PACKET_ENTRIES) != 0) { 575 mPerPacketRingBuffer = buffer; 576 } 577 } 578 } else { 579 mLog.wC("no ring buffers found"); 580 } 581 582 return mRingBuffers != null; 583 } 584 resizeRingBuffers()585 private void resizeRingBuffers() { 586 for (ByteArrayRingBuffer byteArrayRingBuffer : mRingBufferData.values()) { 587 byteArrayRingBuffer.resize(mMaxRingBufferSizeBytes); 588 } 589 } 590 startLoggingRingBuffers()591 private void startLoggingRingBuffers() { 592 if (!isHalVerboseLoggingEnabled()) { 593 clearVerboseLogs(); 594 } 595 if (mRingBuffers == null) { 596 fetchRingBuffers(); 597 } 598 if (mRingBuffers != null) { 599 // Log level may have changed, so restart logging with new levels. 600 stopLoggingAllBuffers(); 601 resizeRingBuffers(); 602 startLoggingAllExceptPerPacketBuffers(); 603 } 604 } 605 startLoggingAllExceptPerPacketBuffers()606 private boolean startLoggingAllExceptPerPacketBuffers() { 607 608 if (mRingBuffers == null) { 609 if (DBG) mLog.tC("No ring buffers to log anything!"); 610 return false; 611 } 612 613 for (WifiNative.RingBufferStatus buffer : mRingBuffers){ 614 615 if ((buffer.flag & RING_BUFFER_FLAG_HAS_PER_PACKET_ENTRIES) != 0) { 616 /* skip per-packet-buffer */ 617 if (DBG) mLog.trace("skipped per packet logging ring %").c(buffer.name).flush(); 618 continue; 619 } 620 621 startLoggingRingBuffer(buffer); 622 } 623 624 return true; 625 } 626 startLoggingRingBuffer(WifiNative.RingBufferStatus buffer)627 private boolean startLoggingRingBuffer(WifiNative.RingBufferStatus buffer) { 628 629 int minInterval = MinWakeupIntervals[mHalLogLevel]; 630 int minDataSize = MinBufferSizes[mHalLogLevel]; 631 632 if (!mWifiNative.startLoggingRingBuffer( 633 mHalLogLevel, 0, minInterval, minDataSize, buffer.name)) { 634 if (DBG) mLog.warn("Could not start logging ring %").c(buffer.name).flush(); 635 return false; 636 } 637 638 return true; 639 } 640 stopLoggingRingBuffer(WifiNative.RingBufferStatus buffer)641 private boolean stopLoggingRingBuffer(WifiNative.RingBufferStatus buffer) { 642 if (!mWifiNative.startLoggingRingBuffer(0, 0, 0, 0, buffer.name)) { 643 if (DBG) mLog.warn("Could not stop logging ring %").c(buffer.name).flush(); 644 } 645 return true; 646 } 647 stopLoggingAllBuffers()648 private boolean stopLoggingAllBuffers() { 649 if (mRingBuffers != null) { 650 for (WifiNative.RingBufferStatus buffer : mRingBuffers) { 651 stopLoggingRingBuffer(buffer); 652 } 653 } 654 return true; 655 } 656 enableVerboseLoggingForDogfood()657 private boolean enableVerboseLoggingForDogfood() { 658 return true; 659 660 } 661 flushDump(int errorCode)662 private boolean flushDump(int errorCode) { 663 if (errorCode == REPORT_REASON_USER_ACTION) return false; 664 665 long currentTime = mClock.getWallClockMillis(); 666 int index = mLastDumpTime.indexOfKey(errorCode); 667 if (index >= 0) { 668 if (currentTime - mLastDumpTime.valueAt(index) < MIN_DUMP_TIME_WINDOW_MILLIS) { 669 return false; 670 } 671 } 672 if (!mWifiNative.flushRingBufferData()) { 673 mLog.wC("could not flush ringbuffer"); 674 return false; 675 } 676 mLastDumpTime.put(errorCode, currentTime); 677 return true; 678 } 679 captureBugreport(int errorCode, boolean captureFWDump)680 private BugReport captureBugreport(int errorCode, boolean captureFWDump) { 681 BugReport report = new BugReport(); 682 report.errorCode = errorCode; 683 report.systemTimeMs = System.currentTimeMillis(); 684 report.kernelTimeNanos = System.nanoTime(); 685 686 synchronized (this) { 687 if (mRingBuffers != null) { 688 for (WifiNative.RingBufferStatus buffer : mRingBuffers) { 689 /* this will push data in mRingBuffers */ 690 mWifiNative.getRingBufferData(buffer.name); 691 ByteArrayRingBuffer data = mRingBufferData.get(buffer.name); 692 byte[][] buffers = new byte[data.getNumBuffers()][]; 693 for (int i = 0; i < data.getNumBuffers(); i++) { 694 buffers[i] = data.getBuffer(i).clone(); 695 } 696 report.ringBuffers.put(buffer.name, buffers); 697 } 698 } 699 } 700 701 // getLogcat*() is very slow, do not put them inside `synchronize(this)`! 702 report.logcatLines = getLogcatSystem(127); 703 report.kernelLogLines = getLogcatKernel(127); 704 705 if (captureFWDump) { 706 report.fwMemoryDump = mWifiNative.getFwMemoryDump(); 707 report.mDriverStateDump = mWifiNative.getDriverStateDump(); 708 } 709 return report; 710 } 711 712 @VisibleForTesting getBugReports()713 synchronized LimitedCircularArray<BugReport> getBugReports() { 714 return mLastBugReports; 715 } 716 717 @VisibleForTesting getAlertReports()718 synchronized LimitedCircularArray<BugReport> getAlertReports() { 719 return mLastAlerts; 720 } 721 compressToBase64(byte[] input)722 private String compressToBase64(byte[] input) { 723 String result; 724 //compress 725 Deflater compressor = new Deflater(); 726 compressor.setLevel(Deflater.BEST_SPEED); 727 compressor.setInput(input); 728 compressor.finish(); 729 ByteArrayOutputStream bos = new ByteArrayOutputStream(input.length); 730 final byte[] buf = new byte[1024]; 731 732 while (!compressor.finished()) { 733 int count = compressor.deflate(buf); 734 bos.write(buf, 0, count); 735 } 736 737 try { 738 compressor.end(); 739 bos.close(); 740 } catch (IOException e) { 741 mLog.wC("ByteArrayOutputStream close error"); 742 result = android.util.Base64.encodeToString(input, Base64.DEFAULT); 743 return result; 744 } 745 746 byte[] compressed = bos.toByteArray(); 747 if (DBG) { 748 mLog.dump("length is: %").c(compressed == null ? 0 : compressed.length).flush(); 749 } 750 751 //encode 752 result = android.util.Base64.encodeToString( 753 compressed.length < input.length ? compressed : input , Base64.DEFAULT); 754 755 if (DBG) { 756 mLog.dump("FwMemoryDump length is: %").c(result.length()).flush(); 757 } 758 759 return result; 760 } 761 readLogcatStreamLinesWithTimeout( BufferedReader inReader, List<String> outLinesList)762 private void readLogcatStreamLinesWithTimeout( 763 BufferedReader inReader, List<String> outLinesList) throws IOException { 764 long startTimeMs = mClock.getElapsedSinceBootMillis(); 765 while (mClock.getElapsedSinceBootMillis() < startTimeMs + LOGCAT_READ_TIMEOUT_MILLIS) { 766 // If there is a burst of data, continue reading without checking for timeout. 767 while (inReader.ready()) { 768 String line = inReader.readLine(); 769 if (line == null) return; // end of stream. 770 outLinesList.add(line); 771 } 772 mClock.sleep(LOGCAT_READ_TIMEOUT_MILLIS / 10); 773 } 774 } 775 776 /** This method is thread safe */ getLogcat(String logcatSections, int maxLines)777 private ArrayList<String> getLogcat(String logcatSections, int maxLines) { 778 ArrayList<String> lines = new ArrayList<>(maxLines); 779 Process process = null; 780 try { 781 process = mJavaRuntime.exec("logcat -b " + logcatSections + " -t " + maxLines); 782 readLogcatStreamLinesWithTimeout( 783 new BufferedReader(new InputStreamReader(process.getInputStream())), lines); 784 readLogcatStreamLinesWithTimeout( 785 new BufferedReader(new InputStreamReader(process.getErrorStream())), lines); 786 process.waitFor(LOGCAT_PROC_TIMEOUT_MILLIS, TimeUnit.MILLISECONDS); 787 } catch (InterruptedException|IOException e) { 788 mLog.dump("Exception while capturing logcat: %").c(e.toString()).flush(); 789 } finally { 790 if (process != null) { 791 process.destroy(); 792 } 793 } 794 return lines; 795 } 796 797 /** This method is thread safe */ getLogcatSystem(int maxLines)798 private ArrayList<String> getLogcatSystem(int maxLines) { 799 return getLogcat("main,system,crash", maxLines); 800 } 801 802 /** This method is thread safe */ getLogcatKernel(int maxLines)803 private ArrayList<String> getLogcatKernel(int maxLines) { 804 return getLogcat("kernel", maxLines); 805 } 806 807 /** Packet fate reporting */ 808 private PacketFates mPacketFatesForLastFailure; 809 810 static class PacketFates { 811 public final String clientModeManagerInfo; 812 @NonNull public final List<WifiNative.FateReport> mergedFates; 813 PacketFates(ClientModeManager clientModeManager)814 PacketFates(ClientModeManager clientModeManager) { 815 clientModeManagerInfo = clientModeManager.toString(); 816 mergedFates = new ArrayList<WifiNative.FateReport>(); 817 mergedFates.addAll(clientModeManager.getTxPktFates()); 818 mergedFates.addAll(clientModeManager.getRxPktFates()); 819 mergedFates.sort(Comparator.comparing(fateReport -> fateReport.mDriverTimestampUSec)); 820 } 821 } 822 fetchPacketFatesForAllClientIfaces()823 private @NonNull List<PacketFates> fetchPacketFatesForAllClientIfaces() { 824 List<ClientModeManager> clientModeManagers = 825 mWifiInjector.getActiveModeWarden().getClientModeManagers(); 826 List<PacketFates> packetFates = new ArrayList<>(); 827 for (ClientModeManager cm : clientModeManagers) { 828 packetFates.add(new PacketFates(cm)); 829 } 830 return packetFates; 831 } 832 dumpPacketFates(PrintWriter pw)833 private void dumpPacketFates(PrintWriter pw) { 834 dumpPacketFatesInternal(pw, "Last failed connection fates", mPacketFatesForLastFailure, 835 isHalVerboseLoggingEnabled()); 836 for (PacketFates fates : fetchPacketFatesForAllClientIfaces()) { 837 dumpPacketFatesInternal(pw, "Latest fates", fates, isHalVerboseLoggingEnabled()); 838 } 839 } 840 dumpPacketFatesInternal(PrintWriter pw, String description, PacketFates packetFates, boolean verbose)841 private static void dumpPacketFatesInternal(PrintWriter pw, String description, 842 PacketFates packetFates, boolean verbose) { 843 if (packetFates == null) { 844 pw.format("No fates fetched for \"%s\"\n", description); 845 return; 846 } 847 if (packetFates.mergedFates.size() == 0) { 848 pw.format("HAL provided zero fates for \"%s\"\n", description); 849 return; 850 } 851 852 pw.format("--------------------- %s ----------------------\n", description); 853 pw.format("ClientModeManagerInfo=%s ---------------\n", packetFates.clientModeManagerInfo); 854 855 StringBuilder verboseOutput = new StringBuilder(); 856 pw.print(WifiNative.FateReport.getTableHeader()); 857 for (WifiNative.FateReport fate : packetFates.mergedFates) { 858 pw.print(fate.toTableRowString()); 859 if (verbose) { 860 // Important: only print Personally Identifiable Information (PII) if verbose 861 // logging is turned on. 862 verboseOutput.append(fate.toVerboseStringWithPiiAllowed()); 863 verboseOutput.append("\n"); 864 } 865 } 866 867 if (verbose) { 868 pw.format("\n>>> VERBOSE PACKET FATE DUMP <<<\n\n"); 869 pw.print(verboseOutput.toString()); 870 } 871 872 pw.println("--------------------------------------------------------------------"); 873 } 874 875 /** 876 * Enable packet fate monitoring. 877 * 878 * @param ifaceName Name of the interface. 879 */ startPktFateMonitoring(@onNull String ifaceName)880 public void startPktFateMonitoring(@NonNull String ifaceName) { 881 if (!mWifiNative.startPktFateMonitoring(ifaceName)) { 882 mLog.wC("Failed to start packet fate monitoring"); 883 } 884 } 885 886 /** 887 * Builder for communicating with betterbug. 888 */ 889 private class BetterBugIntentBuilder { 890 private static final boolean DEFAULT_AUTO_UPLOAD_ENABLED = false; 891 private static final boolean DEFAULT_BUGREPORT_REQUIRED = true; 892 // Component: Android > Android OS & Apps > Systems > wifi 893 private static final long DEFAULT_COMPONENT_ID = 33618L; 894 private static final String DEFAULT_BUG_ASSIGNEE = "android-wifi-team@google.com"; 895 896 private static final String EXTRA_DEEPLINK = "EXTRA_DEEPLINK"; 897 private static final String EXTRA_ISSUE_TITLE = "EXTRA_ISSUE_TITLE"; 898 private static final String EXTRA_ISSUE_DESCRIPTION = "EXTRA_ISSUE_DESCRIPTION"; 899 private static final String EXTRA_DEEPLINK_SILENT = "EXTRA_DEEPLINK_SILENT"; 900 private static final String EXTRA_ADDITIONAL_COMMENT = "EXTRA_ADDITIONAL_COMMENT"; 901 private static final String EXTRA_HOTLIST_ID_LIST = "EXTRA_HOTLIST_ID_LIST"; 902 private static final String EXTRA_TARGET_PACKAGE = "EXTRA_TARGET_PACKAGE"; 903 private static final String EXTRA_REQUIRE_BUGREPORT = "EXTRA_REQUIRE_BUGREPORT"; 904 private static final String EXTRA_HAPPENED_TIME = "EXTRA_HAPPENED_TIME"; 905 private static final String EXTRA_REPRO_STEPS = "EXTRA_REPRO_STEPS"; 906 private static final String EXTRA_ACTUALLY_HAPPENED = "EXTRA_ACTUALLY_HAPPENED"; 907 private static final String EXTRA_BUG_ASSIGNEE = "EXTRA_BUG_ASSIGNEE"; 908 private static final String EXTRA_CC = "EXTRA_CC"; 909 private static final String EXTRA_COMPONENT_ID = "EXTRA_COMPONENT_ID"; 910 911 private final Intent mBetterBugIntent; 912 BetterBugIntentBuilder()913 BetterBugIntentBuilder() { 914 mBetterBugIntent = new Intent() 915 .setAction(mContext.getResources().getString( 916 R.string.config_wifiBugreportDeepLink)) 917 .putExtra(EXTRA_DEEPLINK, true); 918 setAutoUpload(DEFAULT_AUTO_UPLOAD_ENABLED); 919 setBugreportRequired(DEFAULT_BUGREPORT_REQUIRED); 920 setBugAssignee(DEFAULT_BUG_ASSIGNEE); 921 setComponentId(DEFAULT_COMPONENT_ID); 922 } 923 setIssueTitle(String title)924 public BetterBugIntentBuilder setIssueTitle(String title) { 925 mBetterBugIntent.putExtra(EXTRA_ISSUE_TITLE, title); 926 return this; 927 } 928 setIssueDescription(String description)929 public BetterBugIntentBuilder setIssueDescription(String description) { 930 mBetterBugIntent.putExtra(EXTRA_ISSUE_DESCRIPTION, description); 931 return this; 932 } 933 setAutoUpload(boolean autoUploadEnabled)934 public BetterBugIntentBuilder setAutoUpload(boolean autoUploadEnabled) { 935 mBetterBugIntent.putExtra(EXTRA_DEEPLINK_SILENT, autoUploadEnabled); 936 return this; 937 } 938 setTargetPackage(String targetPackage)939 public BetterBugIntentBuilder setTargetPackage(String targetPackage) { 940 mBetterBugIntent.putExtra(EXTRA_TARGET_PACKAGE, targetPackage); 941 return this; 942 } 943 setComponentId(long componentId)944 public BetterBugIntentBuilder setComponentId(long componentId) { 945 mBetterBugIntent.putExtra(EXTRA_COMPONENT_ID, componentId); 946 return this; 947 } 948 setBugreportRequired(boolean isBugreportRequired)949 public BetterBugIntentBuilder setBugreportRequired(boolean isBugreportRequired) { 950 mBetterBugIntent.putExtra(EXTRA_REQUIRE_BUGREPORT, isBugreportRequired); 951 return this; 952 } 953 setHappenedTimestamp(long happenedTimeSinceEpochMs)954 public BetterBugIntentBuilder setHappenedTimestamp(long happenedTimeSinceEpochMs) { 955 mBetterBugIntent.putExtra(EXTRA_HAPPENED_TIME, happenedTimeSinceEpochMs); 956 return this; 957 } 958 setReproSteps(List<String> reproSteps)959 public BetterBugIntentBuilder setReproSteps(List<String> reproSteps) { 960 if (reproSteps == null) { 961 Log.e(TAG, "List reproSteps is null."); 962 return this; 963 } 964 mBetterBugIntent.putExtra(EXTRA_REPRO_STEPS, new ArrayList<>(reproSteps)); 965 return this; 966 } 967 setWhatActuallyHappenedDescription(String whatHappened)968 public BetterBugIntentBuilder setWhatActuallyHappenedDescription(String whatHappened) { 969 mBetterBugIntent.putExtra(EXTRA_ACTUALLY_HAPPENED, whatHappened); 970 return this; 971 } 972 setAdditionalComment(String additionalComment)973 public BetterBugIntentBuilder setAdditionalComment(String additionalComment) { 974 mBetterBugIntent.putExtra(EXTRA_ADDITIONAL_COMMENT, additionalComment); 975 return this; 976 } 977 setBugAssignee(String assignee)978 public BetterBugIntentBuilder setBugAssignee(String assignee) { 979 mBetterBugIntent.putExtra(EXTRA_BUG_ASSIGNEE, assignee); 980 return this; 981 } 982 setBugCc(String ccList)983 public BetterBugIntentBuilder setBugCc(String ccList) { 984 mBetterBugIntent.putExtra(EXTRA_CC, ccList); 985 return this; 986 } 987 setBuganizerHotlist(List<Long> hotlistIds)988 public BetterBugIntentBuilder setBuganizerHotlist(List<Long> hotlistIds) { 989 mBetterBugIntent.putExtra(EXTRA_HOTLIST_ID_LIST, hotlistIds.toArray()); 990 return this; 991 } 992 build()993 public Intent build() { 994 return mBetterBugIntent; 995 } 996 } 997 takeBugreportThroughBetterBug(String bugTitle, String bugDetail)998 private boolean takeBugreportThroughBetterBug(String bugTitle, String bugDetail) { 999 Intent launchBetterBugIntent = 1000 new BetterBugIntentBuilder() 1001 .setIssueTitle(bugTitle) 1002 .setIssueDescription(bugDetail) 1003 .setHappenedTimestamp(System.currentTimeMillis()) 1004 .build(); 1005 1006 boolean isIntentUnSafe = mContext.getPackageManager().queryIntentActivities( 1007 launchBetterBugIntent, PackageManager.MATCH_SYSTEM_ONLY).isEmpty(); 1008 if (isIntentUnSafe) { 1009 Log.d(TAG, 1010 "BetterBugIntent is unsafe and skip bugreport through betterBug " + bugTitle); 1011 return false; 1012 } 1013 1014 try { 1015 launchBetterBugIntent.addFlags(Intent.FLAG_RECEIVER_FOREGROUND); 1016 mContext.startActivity(launchBetterBugIntent); 1017 Log.d(TAG, "Taking the bugreport " + bugTitle + "(" + bugDetail + ")"); 1018 mLastBugReportTime = mClock.getWallClockMillis(); 1019 return true; 1020 } catch (RuntimeException e) { 1021 Log.e(TAG, "Error taking bugreport: " + e); 1022 return false; 1023 } 1024 } 1025 shouldTakeBugreport(String bugTitle, String bugDetail)1026 private boolean shouldTakeBugreport(String bugTitle, String bugDetail) { 1027 long currentTimeMs = mClock.getWallClockMillis(); 1028 long timeSinceLastUploadMs = currentTimeMs - mLastBugReportTime; 1029 if (timeSinceLastUploadMs 1030 < mWifiInjector.getDeviceConfigFacade().getBugReportMinWindowMs() 1031 && mLastBugReportTime > 0) { 1032 Log.d(TAG, "Bugreport was filed recently, skip " + bugTitle + "(" + bugDetail + ")"); 1033 return false; 1034 } 1035 String titleAndDetail = bugTitle + bugDetail; 1036 if (mWifiInjector.getDeviceConfigFacade().getDisabledAutoBugreportTitleAndDetails() 1037 .contains(titleAndDetail)) { 1038 Log.d(TAG, "Bugreport explicitly disabled " + bugTitle + "(" + bugDetail + ")"); 1039 return false; 1040 } 1041 return true; 1042 } 1043 1044 /** 1045 * Initiates a system-level bug report if there is no bug report taken recently. 1046 * This is done in a non-blocking fashion. 1047 */ takeBugReport(String bugTitle, String bugDetail)1048 public void takeBugReport(String bugTitle, String bugDetail) { 1049 if (mBuildProperties.isUserBuild() || !mContext.getResources().getBoolean( 1050 R.bool.config_wifi_diagnostics_bugreport_enabled)) { 1051 Log.d(TAG, "Bugreport can be triggered only in userdebug build, skip " + bugTitle + "(" 1052 + bugDetail + ")"); 1053 return; 1054 } 1055 1056 if (!shouldTakeBugreport(bugTitle, bugDetail)) { 1057 return; 1058 } 1059 1060 mWifiMetrics.logBugReport(); 1061 if (!takeBugreportThroughBetterBug(bugTitle, bugDetail)) { 1062 takeBugReportThroughBugreportManager(bugTitle, bugDetail); 1063 } 1064 } 1065 } 1066