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