11716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal/*
21716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal * Copyright (C) 2017 The Android Open Source Project
31716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal *
41716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal * Licensed under the Apache License, Version 2.0 (the "License");
51716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal * you may not use this file except in compliance with the License.
61716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal * You may obtain a copy of the License at
71716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal *
81716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal *      http://www.apache.org/licenses/LICENSE-2.0
91716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal *
101716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal * Unless required by applicable law or agreed to in writing, software
111716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal * distributed under the License is distributed on an "AS IS" BASIS,
121716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
131716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal * See the License for the specific language governing permissions and
141716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal * limitations under the License.
151716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal */
161716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal
171716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawalpackage com.android.server.wifi;
181716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal
191716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawalimport android.os.FileUtils;
201716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal
211716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawalimport com.android.internal.annotations.VisibleForTesting;
221716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal
231716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawalimport libcore.io.IoUtils;
241716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal
251716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawalimport java.io.FileInputStream;
261716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawalimport java.io.IOException;
271716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawalimport java.io.PrintWriter;
281716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal
291716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal/**
301716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal * Provides a facility for capturing kernel trace events related to Wifi control and data paths.
311716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal */
321716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawalpublic class LastMileLogger {
331716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal    public LastMileLogger(WifiInjector injector) {
341716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal        this(injector, WIFI_EVENT_BUFFER_PATH, WIFI_EVENT_ENABLE_PATH, WIFI_EVENT_RELEASE_PATH);
351716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal    }
361716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal
371716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal    @VisibleForTesting
381716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal    public LastMileLogger(WifiInjector injector, String bufferPath, String enablePath,
391716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal                          String releasePath) {
401716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal        mLog = injector.makeLog(TAG);
411716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal        mEventBufferPath = bufferPath;
421716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal        mEventEnablePath = enablePath;
431716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal        mEventReleasePath = releasePath;
441716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal    }
451716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal
461716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal    /**
471716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal     * Informs LastMileLogger that a connection event has occurred.
483f2187fdcc3ed55c909cb4cdee589744655d3243mukesh agrawal     * @param connectionId A non-negative connection identifier, or -1 to indicate unknown
491716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal     * @param event an event defined in BaseWifiDiagnostics
501716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal     */
513f2187fdcc3ed55c909cb4cdee589744655d3243mukesh agrawal    public void reportConnectionEvent(long connectionId, byte event) {
523355eb4392aabfae9453e7d6f11d9f0620bf5daemukesh agrawal        if (connectionId < 0) {
533355eb4392aabfae9453e7d6f11d9f0620bf5daemukesh agrawal            mLog.warn("Ignoring negative connection id: %").c(connectionId);
543355eb4392aabfae9453e7d6f11d9f0620bf5daemukesh agrawal            return;
553355eb4392aabfae9453e7d6f11d9f0620bf5daemukesh agrawal        }
563355eb4392aabfae9453e7d6f11d9f0620bf5daemukesh agrawal
571716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal        switch (event) {
581716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal            case BaseWifiDiagnostics.CONNECTION_EVENT_STARTED:
593355eb4392aabfae9453e7d6f11d9f0620bf5daemukesh agrawal                mPendingConnectionId = connectionId;
601716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal                enableTracing();
611716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal                return;
621716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal            case BaseWifiDiagnostics.CONNECTION_EVENT_SUCCEEDED:
633355eb4392aabfae9453e7d6f11d9f0620bf5daemukesh agrawal                mPendingConnectionId = -1;
641716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal                disableTracing();
651716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal                return;
661716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal            case BaseWifiDiagnostics.CONNECTION_EVENT_FAILED:
673355eb4392aabfae9453e7d6f11d9f0620bf5daemukesh agrawal                if (connectionId >= mPendingConnectionId) {
683355eb4392aabfae9453e7d6f11d9f0620bf5daemukesh agrawal                    mPendingConnectionId = -1;
693355eb4392aabfae9453e7d6f11d9f0620bf5daemukesh agrawal                    disableTracing();
703355eb4392aabfae9453e7d6f11d9f0620bf5daemukesh agrawal                    mLastMileLogForLastFailure = readTrace();
713355eb4392aabfae9453e7d6f11d9f0620bf5daemukesh agrawal                    return;
723355eb4392aabfae9453e7d6f11d9f0620bf5daemukesh agrawal                } else {
733355eb4392aabfae9453e7d6f11d9f0620bf5daemukesh agrawal                    // Spurious failure message. Here's one scenario where this might happen:
743355eb4392aabfae9453e7d6f11d9f0620bf5daemukesh agrawal                    // t=00sec      start first connection attempt
753355eb4392aabfae9453e7d6f11d9f0620bf5daemukesh agrawal                    // t=30sec      start second connection attempt
763355eb4392aabfae9453e7d6f11d9f0620bf5daemukesh agrawal                    // t=60sec      timeout first connection attempt
773355eb4392aabfae9453e7d6f11d9f0620bf5daemukesh agrawal                    // We should not stop tracing in this case, since the second connection attempt
783355eb4392aabfae9453e7d6f11d9f0620bf5daemukesh agrawal                    // is still in progress.
793355eb4392aabfae9453e7d6f11d9f0620bf5daemukesh agrawal                    return;
803355eb4392aabfae9453e7d6f11d9f0620bf5daemukesh agrawal                }
811716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal        }
821716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal    }
831716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal
841716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal    /**
851716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal     * Dumps the contents of the log.
861716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal     * @param pw the PrintWriter that will receive the dump
871716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal     */
881716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal    public void dump(PrintWriter pw) {
891716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal        dumpInternal(pw, "Last failed last-mile log", mLastMileLogForLastFailure);
901716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal        dumpInternal(pw, "Latest last-mile log", readTrace());
911716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal        mLastMileLogForLastFailure = null;
921716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal    }
931716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal
941716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal    private static final String TAG = "LastMileLogger";
951716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal    private static final String WIFI_EVENT_BUFFER_PATH =
961716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal            "/sys/kernel/debug/tracing/instances/wifi/trace";
971716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal    private static final String WIFI_EVENT_ENABLE_PATH =
981716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal            "/sys/kernel/debug/tracing/instances/wifi/tracing_on";
991716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal    private static final String WIFI_EVENT_RELEASE_PATH =
1001716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal            "/sys/kernel/debug/tracing/instances/wifi/free_buffer";
1011716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal
1021716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal    private final String mEventBufferPath;
1031716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal    private final String mEventEnablePath;
1041716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal    private final String mEventReleasePath;
1051716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal    private WifiLog mLog;
1061716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal    private byte[] mLastMileLogForLastFailure;
1071716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal    private FileInputStream mLastMileTraceHandle;
1083355eb4392aabfae9453e7d6f11d9f0620bf5daemukesh agrawal    private long mPendingConnectionId = -1;
1091716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal
1101716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal    private void enableTracing() {
1112c77fc78df8f1e3175c3cd184da1e8301aee75c8mukesh agrawal        if (!ensureFailSafeIsArmed()) {
1122c77fc78df8f1e3175c3cd184da1e8301aee75c8mukesh agrawal            mLog.wC("Failed to arm fail-safe.");
1132c77fc78df8f1e3175c3cd184da1e8301aee75c8mukesh agrawal            return;
1142c77fc78df8f1e3175c3cd184da1e8301aee75c8mukesh agrawal        }
1152c77fc78df8f1e3175c3cd184da1e8301aee75c8mukesh agrawal
1161716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal        try {
1171716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal            FileUtils.stringToFile(mEventEnablePath, "1");
1181716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal        } catch (IOException e) {
1191716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal            mLog.warn("Failed to start event tracing: %").r(e.getMessage()).flush();
1201716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal        }
1211716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal    }
1221716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal
1231716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal    private void disableTracing() {
1241716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal        try {
1251716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal            FileUtils.stringToFile(mEventEnablePath, "0");
1261716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal        } catch (IOException e) {
1271716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal            mLog.warn("Failed to stop event tracing: %").r(e.getMessage()).flush();
1281716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal        }
1291716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal    }
1301716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal
1311716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal    private byte[] readTrace() {
1321716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal        try {
1331716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal            return IoUtils.readFileAsByteArray(mEventBufferPath);
1341716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal        } catch (IOException e) {
1351716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal            mLog.warn("Failed to read event trace: %").r(e.getMessage()).flush();
1361716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal            return new byte[0];
1371716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal        }
1381716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal    }
1391716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal
1402c77fc78df8f1e3175c3cd184da1e8301aee75c8mukesh agrawal    private boolean ensureFailSafeIsArmed() {
1412c77fc78df8f1e3175c3cd184da1e8301aee75c8mukesh agrawal        if (mLastMileTraceHandle != null) {
1422c77fc78df8f1e3175c3cd184da1e8301aee75c8mukesh agrawal            return true;
1432c77fc78df8f1e3175c3cd184da1e8301aee75c8mukesh agrawal        }
1442c77fc78df8f1e3175c3cd184da1e8301aee75c8mukesh agrawal
1452c77fc78df8f1e3175c3cd184da1e8301aee75c8mukesh agrawal        try {
1462c77fc78df8f1e3175c3cd184da1e8301aee75c8mukesh agrawal            // This file provides fail-safe behavior for Last-Mile logging. Given that we:
1472c77fc78df8f1e3175c3cd184da1e8301aee75c8mukesh agrawal            // 1. Set the disable_on_free option in the trace_options pseudo-file
1482c77fc78df8f1e3175c3cd184da1e8301aee75c8mukesh agrawal            //    (see wifi-events.rc), and
1492c77fc78df8f1e3175c3cd184da1e8301aee75c8mukesh agrawal            // 2. Hold the WIFI_EVENT_RELEASE_PATH open,
1502c77fc78df8f1e3175c3cd184da1e8301aee75c8mukesh agrawal            //
1512c77fc78df8f1e3175c3cd184da1e8301aee75c8mukesh agrawal            // Then, when this process dies, the kernel will automatically disable any
1522c77fc78df8f1e3175c3cd184da1e8301aee75c8mukesh agrawal            // tracing in the wifi trace instance.
1532c77fc78df8f1e3175c3cd184da1e8301aee75c8mukesh agrawal            //
1542c77fc78df8f1e3175c3cd184da1e8301aee75c8mukesh agrawal            // Note that, despite Studio's suggestion that |mLastMileTraceHandle| could be demoted
1552c77fc78df8f1e3175c3cd184da1e8301aee75c8mukesh agrawal            // to a local variable, we need to stick with a field. Otherwise, the handle could be
1562c77fc78df8f1e3175c3cd184da1e8301aee75c8mukesh agrawal            // garbage collected.
1572c77fc78df8f1e3175c3cd184da1e8301aee75c8mukesh agrawal            mLastMileTraceHandle = new FileInputStream(mEventReleasePath);
1582c77fc78df8f1e3175c3cd184da1e8301aee75c8mukesh agrawal            return true;
1592c77fc78df8f1e3175c3cd184da1e8301aee75c8mukesh agrawal        } catch (IOException e) {
1602c77fc78df8f1e3175c3cd184da1e8301aee75c8mukesh agrawal            mLog.warn("Failed to open free_buffer pseudo-file: %").r(e.getMessage()).flush();
1612c77fc78df8f1e3175c3cd184da1e8301aee75c8mukesh agrawal            return false;
1622c77fc78df8f1e3175c3cd184da1e8301aee75c8mukesh agrawal        }
1632c77fc78df8f1e3175c3cd184da1e8301aee75c8mukesh agrawal    }
1642c77fc78df8f1e3175c3cd184da1e8301aee75c8mukesh agrawal
1651716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal    private static void dumpInternal(PrintWriter pw, String description, byte[] lastMileLog) {
1661716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal        if (lastMileLog == null || lastMileLog.length < 1) {
1671716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal            pw.format("No last mile log for \"%s\"\n", description);
1681716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal            return;
1691716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal        }
1701716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal
1711716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal        pw.format("-------------------------- %s ---------------------------\n", description);
1721716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal        pw.print(new String(lastMileLog));
1731716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal        pw.println("--------------------------------------------------------------------");
1741716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal    }
1751716aa7ad8e00a41980c4120c2104b25fe36630emukesh agrawal}
176