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