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