Home | History | Annotate | Download | only in server
      1 /*
      2  * Copyright (C) 2007 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;
     18 
     19 import android.net.LocalSocket;
     20 import android.net.LocalSocketAddress;
     21 import android.os.Build;
     22 import android.os.Handler;
     23 import android.os.Message;
     24 import android.os.SystemClock;
     25 import android.util.LocalLog;
     26 import android.util.Slog;
     27 
     28 import com.android.internal.annotations.VisibleForTesting;
     29 import com.google.android.collect.Lists;
     30 
     31 import java.io.FileDescriptor;
     32 import java.io.IOException;
     33 import java.io.InputStream;
     34 import java.io.OutputStream;
     35 import java.io.PrintWriter;
     36 import java.nio.charset.StandardCharsets;
     37 import java.util.ArrayList;
     38 import java.util.concurrent.atomic.AtomicInteger;
     39 import java.util.concurrent.ArrayBlockingQueue;
     40 import java.util.concurrent.BlockingQueue;
     41 import java.util.concurrent.TimeUnit;
     42 import java.util.LinkedList;
     43 
     44 /**
     45  * Generic connector class for interfacing with a native daemon which uses the
     46  * {@code libsysutils} FrameworkListener protocol.
     47  */
     48 final class NativeDaemonConnector implements Runnable, Handler.Callback, Watchdog.Monitor {
     49     private static final boolean LOGD = false;
     50 
     51     private final String TAG;
     52 
     53     private String mSocket;
     54     private OutputStream mOutputStream;
     55     private LocalLog mLocalLog;
     56 
     57     private final ResponseQueue mResponseQueue;
     58 
     59     private INativeDaemonConnectorCallbacks mCallbacks;
     60     private Handler mCallbackHandler;
     61 
     62     private AtomicInteger mSequenceNumber;
     63 
     64     private static final int DEFAULT_TIMEOUT = 1 * 60 * 1000; /* 1 minute */
     65     private static final long WARN_EXECUTE_DELAY_MS = 500; /* .5 sec */
     66 
     67     /** Lock held whenever communicating with native daemon. */
     68     private final Object mDaemonLock = new Object();
     69 
     70     private final int BUFFER_SIZE = 4096;
     71 
     72     NativeDaemonConnector(INativeDaemonConnectorCallbacks callbacks, String socket,
     73             int responseQueueSize, String logTag, int maxLogSize) {
     74         mCallbacks = callbacks;
     75         mSocket = socket;
     76         mResponseQueue = new ResponseQueue(responseQueueSize);
     77         mSequenceNumber = new AtomicInteger(0);
     78         TAG = logTag != null ? logTag : "NativeDaemonConnector";
     79         mLocalLog = new LocalLog(maxLogSize);
     80     }
     81 
     82     @Override
     83     public void run() {
     84         mCallbackHandler = new Handler(FgThread.get().getLooper(), this);
     85 
     86         while (true) {
     87             try {
     88                 listenToSocket();
     89             } catch (Exception e) {
     90                 loge("Error in NativeDaemonConnector: " + e);
     91                 SystemClock.sleep(5000);
     92             }
     93         }
     94     }
     95 
     96     @Override
     97     public boolean handleMessage(Message msg) {
     98         String event = (String) msg.obj;
     99         try {
    100             if (!mCallbacks.onEvent(msg.what, event, NativeDaemonEvent.unescapeArgs(event))) {
    101                 log(String.format("Unhandled event '%s'", event));
    102             }
    103         } catch (Exception e) {
    104             loge("Error handling '" + event + "': " + e);
    105         }
    106         return true;
    107     }
    108 
    109     private LocalSocketAddress determineSocketAddress() {
    110         // If we're testing, set up a socket in a namespace that's accessible to test code.
    111         // In order to ensure that unprivileged apps aren't able to impersonate native daemons on
    112         // production devices, even if said native daemons ill-advisedly pick a socket name that
    113         // starts with __test__, only allow this on debug builds.
    114         if (mSocket.startsWith("__test__") && Build.IS_DEBUGGABLE) {
    115             return new LocalSocketAddress(mSocket);
    116         } else {
    117             return new LocalSocketAddress(mSocket, LocalSocketAddress.Namespace.RESERVED);
    118         }
    119     }
    120 
    121     private void listenToSocket() throws IOException {
    122         LocalSocket socket = null;
    123 
    124         try {
    125             socket = new LocalSocket();
    126             LocalSocketAddress address = determineSocketAddress();
    127 
    128             socket.connect(address);
    129 
    130             InputStream inputStream = socket.getInputStream();
    131             synchronized (mDaemonLock) {
    132                 mOutputStream = socket.getOutputStream();
    133             }
    134 
    135             mCallbacks.onDaemonConnected();
    136 
    137             byte[] buffer = new byte[BUFFER_SIZE];
    138             int start = 0;
    139 
    140             while (true) {
    141                 int count = inputStream.read(buffer, start, BUFFER_SIZE - start);
    142                 if (count < 0) {
    143                     loge("got " + count + " reading with start = " + start);
    144                     break;
    145                 }
    146 
    147                 // Add our starting point to the count and reset the start.
    148                 count += start;
    149                 start = 0;
    150 
    151                 for (int i = 0; i < count; i++) {
    152                     if (buffer[i] == 0) {
    153                         final String rawEvent = new String(
    154                                 buffer, start, i - start, StandardCharsets.UTF_8);
    155                         log("RCV <- {" + rawEvent + "}");
    156 
    157                         try {
    158                             final NativeDaemonEvent event = NativeDaemonEvent.parseRawEvent(
    159                                     rawEvent);
    160                             if (event.isClassUnsolicited()) {
    161                                 // TODO: migrate to sending NativeDaemonEvent instances
    162                                 mCallbackHandler.sendMessage(mCallbackHandler.obtainMessage(
    163                                         event.getCode(), event.getRawEvent()));
    164                             } else {
    165                                 mResponseQueue.add(event.getCmdNumber(), event);
    166                             }
    167                         } catch (IllegalArgumentException e) {
    168                             log("Problem parsing message: " + rawEvent + " - " + e);
    169                         }
    170 
    171                         start = i + 1;
    172                     }
    173                 }
    174                 if (start == 0) {
    175                     final String rawEvent = new String(buffer, start, count, StandardCharsets.UTF_8);
    176                     log("RCV incomplete <- {" + rawEvent + "}");
    177                 }
    178 
    179                 // We should end at the amount we read. If not, compact then
    180                 // buffer and read again.
    181                 if (start != count) {
    182                     final int remaining = BUFFER_SIZE - start;
    183                     System.arraycopy(buffer, start, buffer, 0, remaining);
    184                     start = remaining;
    185                 } else {
    186                     start = 0;
    187                 }
    188             }
    189         } catch (IOException ex) {
    190             loge("Communications error: " + ex);
    191             throw ex;
    192         } finally {
    193             synchronized (mDaemonLock) {
    194                 if (mOutputStream != null) {
    195                     try {
    196                         loge("closing stream for " + mSocket);
    197                         mOutputStream.close();
    198                     } catch (IOException e) {
    199                         loge("Failed closing output stream: " + e);
    200                     }
    201                     mOutputStream = null;
    202                 }
    203             }
    204 
    205             try {
    206                 if (socket != null) {
    207                     socket.close();
    208                 }
    209             } catch (IOException ex) {
    210                 loge("Failed closing socket: " + ex);
    211             }
    212         }
    213     }
    214 
    215     /**
    216      * Wrapper around argument that indicates it's sensitive and shouldn't be
    217      * logged.
    218      */
    219     public static class SensitiveArg {
    220         private final Object mArg;
    221 
    222         public SensitiveArg(Object arg) {
    223             mArg = arg;
    224         }
    225 
    226         @Override
    227         public String toString() {
    228             return String.valueOf(mArg);
    229         }
    230     }
    231 
    232     /**
    233      * Make command for daemon, escaping arguments as needed.
    234      */
    235     @VisibleForTesting
    236     static void makeCommand(StringBuilder rawBuilder, StringBuilder logBuilder, int sequenceNumber,
    237             String cmd, Object... args) {
    238         if (cmd.indexOf('\0') >= 0) {
    239             throw new IllegalArgumentException("Unexpected command: " + cmd);
    240         }
    241         if (cmd.indexOf(' ') >= 0) {
    242             throw new IllegalArgumentException("Arguments must be separate from command");
    243         }
    244 
    245         rawBuilder.append(sequenceNumber).append(' ').append(cmd);
    246         logBuilder.append(sequenceNumber).append(' ').append(cmd);
    247         for (Object arg : args) {
    248             final String argString = String.valueOf(arg);
    249             if (argString.indexOf('\0') >= 0) {
    250                 throw new IllegalArgumentException("Unexpected argument: " + arg);
    251             }
    252 
    253             rawBuilder.append(' ');
    254             logBuilder.append(' ');
    255 
    256             appendEscaped(rawBuilder, argString);
    257             if (arg instanceof SensitiveArg) {
    258                 logBuilder.append("[scrubbed]");
    259             } else {
    260                 appendEscaped(logBuilder, argString);
    261             }
    262         }
    263 
    264         rawBuilder.append('\0');
    265     }
    266 
    267     /**
    268      * Issue the given command to the native daemon and return a single expected
    269      * response.
    270      *
    271      * @throws NativeDaemonConnectorException when problem communicating with
    272      *             native daemon, or if the response matches
    273      *             {@link NativeDaemonEvent#isClassClientError()} or
    274      *             {@link NativeDaemonEvent#isClassServerError()}.
    275      */
    276     public NativeDaemonEvent execute(Command cmd) throws NativeDaemonConnectorException {
    277         return execute(cmd.mCmd, cmd.mArguments.toArray());
    278     }
    279 
    280     /**
    281      * Issue the given command to the native daemon and return a single expected
    282      * response. Any arguments must be separated from base command so they can
    283      * be properly escaped.
    284      *
    285      * @throws NativeDaemonConnectorException when problem communicating with
    286      *             native daemon, or if the response matches
    287      *             {@link NativeDaemonEvent#isClassClientError()} or
    288      *             {@link NativeDaemonEvent#isClassServerError()}.
    289      */
    290     public NativeDaemonEvent execute(String cmd, Object... args)
    291             throws NativeDaemonConnectorException {
    292         final NativeDaemonEvent[] events = executeForList(cmd, args);
    293         if (events.length != 1) {
    294             throw new NativeDaemonConnectorException(
    295                     "Expected exactly one response, but received " + events.length);
    296         }
    297         return events[0];
    298     }
    299 
    300     /**
    301      * Issue the given command to the native daemon and return any
    302      * {@link NativeDaemonEvent#isClassContinue()} responses, including the
    303      * final terminal response.
    304      *
    305      * @throws NativeDaemonConnectorException when problem communicating with
    306      *             native daemon, or if the response matches
    307      *             {@link NativeDaemonEvent#isClassClientError()} or
    308      *             {@link NativeDaemonEvent#isClassServerError()}.
    309      */
    310     public NativeDaemonEvent[] executeForList(Command cmd) throws NativeDaemonConnectorException {
    311         return executeForList(cmd.mCmd, cmd.mArguments.toArray());
    312     }
    313 
    314     /**
    315      * Issue the given command to the native daemon and return any
    316      * {@link NativeDaemonEvent#isClassContinue()} responses, including the
    317      * final terminal response. Any arguments must be separated from base
    318      * command so they can be properly escaped.
    319      *
    320      * @throws NativeDaemonConnectorException when problem communicating with
    321      *             native daemon, or if the response matches
    322      *             {@link NativeDaemonEvent#isClassClientError()} or
    323      *             {@link NativeDaemonEvent#isClassServerError()}.
    324      */
    325     public NativeDaemonEvent[] executeForList(String cmd, Object... args)
    326             throws NativeDaemonConnectorException {
    327             return execute(DEFAULT_TIMEOUT, cmd, args);
    328     }
    329 
    330     /**
    331      * Issue the given command to the native daemon and return any {@linke
    332      * NativeDaemonEvent@isClassContinue()} responses, including the final
    333      * terminal response. Note that the timeout does not count time in deep
    334      * sleep. Any arguments must be separated from base command so they can be
    335      * properly escaped.
    336      *
    337      * @throws NativeDaemonConnectorException when problem communicating with
    338      *             native daemon, or if the response matches
    339      *             {@link NativeDaemonEvent#isClassClientError()} or
    340      *             {@link NativeDaemonEvent#isClassServerError()}.
    341      */
    342     public NativeDaemonEvent[] execute(int timeout, String cmd, Object... args)
    343             throws NativeDaemonConnectorException {
    344         final long startTime = SystemClock.elapsedRealtime();
    345 
    346         final ArrayList<NativeDaemonEvent> events = Lists.newArrayList();
    347 
    348         final StringBuilder rawBuilder = new StringBuilder();
    349         final StringBuilder logBuilder = new StringBuilder();
    350         final int sequenceNumber = mSequenceNumber.incrementAndGet();
    351 
    352         makeCommand(rawBuilder, logBuilder, sequenceNumber, cmd, args);
    353 
    354         final String rawCmd = rawBuilder.toString();
    355         final String logCmd = logBuilder.toString();
    356 
    357         log("SND -> {" + logCmd + "}");
    358 
    359         synchronized (mDaemonLock) {
    360             if (mOutputStream == null) {
    361                 throw new NativeDaemonConnectorException("missing output stream");
    362             } else {
    363                 try {
    364                     mOutputStream.write(rawCmd.getBytes(StandardCharsets.UTF_8));
    365                 } catch (IOException e) {
    366                     throw new NativeDaemonConnectorException("problem sending command", e);
    367                 }
    368             }
    369         }
    370 
    371         NativeDaemonEvent event = null;
    372         do {
    373             event = mResponseQueue.remove(sequenceNumber, timeout, logCmd);
    374             if (event == null) {
    375                 loge("timed-out waiting for response to " + logCmd);
    376                 throw new NativeDaemonFailureException(logCmd, event);
    377             }
    378             log("RMV <- {" + event + "}");
    379             events.add(event);
    380         } while (event.isClassContinue());
    381 
    382         final long endTime = SystemClock.elapsedRealtime();
    383         if (endTime - startTime > WARN_EXECUTE_DELAY_MS) {
    384             loge("NDC Command {" + logCmd + "} took too long (" + (endTime - startTime) + "ms)");
    385         }
    386 
    387         if (event.isClassClientError()) {
    388             throw new NativeDaemonArgumentException(logCmd, event);
    389         }
    390         if (event.isClassServerError()) {
    391             throw new NativeDaemonFailureException(logCmd, event);
    392         }
    393 
    394         return events.toArray(new NativeDaemonEvent[events.size()]);
    395     }
    396 
    397     /**
    398      * Append the given argument to {@link StringBuilder}, escaping as needed,
    399      * and surrounding with quotes when it contains spaces.
    400      */
    401     @VisibleForTesting
    402     static void appendEscaped(StringBuilder builder, String arg) {
    403         final boolean hasSpaces = arg.indexOf(' ') >= 0;
    404         if (hasSpaces) {
    405             builder.append('"');
    406         }
    407 
    408         final int length = arg.length();
    409         for (int i = 0; i < length; i++) {
    410             final char c = arg.charAt(i);
    411 
    412             if (c == '"') {
    413                 builder.append("\\\"");
    414             } else if (c == '\\') {
    415                 builder.append("\\\\");
    416             } else {
    417                 builder.append(c);
    418             }
    419         }
    420 
    421         if (hasSpaces) {
    422             builder.append('"');
    423         }
    424     }
    425 
    426     private static class NativeDaemonArgumentException extends NativeDaemonConnectorException {
    427         public NativeDaemonArgumentException(String command, NativeDaemonEvent event) {
    428             super(command, event);
    429         }
    430 
    431         @Override
    432         public IllegalArgumentException rethrowAsParcelableException() {
    433             throw new IllegalArgumentException(getMessage(), this);
    434         }
    435     }
    436 
    437     private static class NativeDaemonFailureException extends NativeDaemonConnectorException {
    438         public NativeDaemonFailureException(String command, NativeDaemonEvent event) {
    439             super(command, event);
    440         }
    441     }
    442 
    443     /**
    444      * Command builder that handles argument list building. Any arguments must
    445      * be separated from base command so they can be properly escaped.
    446      */
    447     public static class Command {
    448         private String mCmd;
    449         private ArrayList<Object> mArguments = Lists.newArrayList();
    450 
    451         public Command(String cmd, Object... args) {
    452             mCmd = cmd;
    453             for (Object arg : args) {
    454                 appendArg(arg);
    455             }
    456         }
    457 
    458         public Command appendArg(Object arg) {
    459             mArguments.add(arg);
    460             return this;
    461         }
    462     }
    463 
    464     /** {@inheritDoc} */
    465     public void monitor() {
    466         synchronized (mDaemonLock) { }
    467     }
    468 
    469     public void dump(FileDescriptor fd, PrintWriter pw, String[] args) {
    470         mLocalLog.dump(fd, pw, args);
    471         pw.println();
    472         mResponseQueue.dump(fd, pw, args);
    473     }
    474 
    475     private void log(String logstring) {
    476         if (LOGD) Slog.d(TAG, logstring);
    477         mLocalLog.log(logstring);
    478     }
    479 
    480     private void loge(String logstring) {
    481         Slog.e(TAG, logstring);
    482         mLocalLog.log(logstring);
    483     }
    484 
    485     private static class ResponseQueue {
    486 
    487         private static class PendingCmd {
    488             public final int cmdNum;
    489             public final String logCmd;
    490 
    491             public BlockingQueue<NativeDaemonEvent> responses =
    492                     new ArrayBlockingQueue<NativeDaemonEvent>(10);
    493 
    494             // The availableResponseCount member is used to track when we can remove this
    495             // instance from the ResponseQueue.
    496             // This is used under the protection of a sync of the mPendingCmds object.
    497             // A positive value means we've had more writers retreive this object while
    498             // a negative value means we've had more readers.  When we've had an equal number
    499             // (it goes to zero) we can remove this object from the mPendingCmds list.
    500             // Note that we may have more responses for this command (and more readers
    501             // coming), but that would result in a new PendingCmd instance being created
    502             // and added with the same cmdNum.
    503             // Also note that when this goes to zero it just means a parity of readers and
    504             // writers have retrieved this object - not that they are done using it.  The
    505             // responses queue may well have more responses yet to be read or may get more
    506             // responses added to it.  But all those readers/writers have retreived and
    507             // hold references to this instance already so it can be removed from
    508             // mPendingCmds queue.
    509             public int availableResponseCount;
    510 
    511             public PendingCmd(int cmdNum, String logCmd) {
    512                 this.cmdNum = cmdNum;
    513                 this.logCmd = logCmd;
    514             }
    515         }
    516 
    517         private final LinkedList<PendingCmd> mPendingCmds;
    518         private int mMaxCount;
    519 
    520         ResponseQueue(int maxCount) {
    521             mPendingCmds = new LinkedList<PendingCmd>();
    522             mMaxCount = maxCount;
    523         }
    524 
    525         public void add(int cmdNum, NativeDaemonEvent response) {
    526             PendingCmd found = null;
    527             synchronized (mPendingCmds) {
    528                 for (PendingCmd pendingCmd : mPendingCmds) {
    529                     if (pendingCmd.cmdNum == cmdNum) {
    530                         found = pendingCmd;
    531                         break;
    532                     }
    533                 }
    534                 if (found == null) {
    535                     // didn't find it - make sure our queue isn't too big before adding
    536                     while (mPendingCmds.size() >= mMaxCount) {
    537                         Slog.e("NativeDaemonConnector.ResponseQueue",
    538                                 "more buffered than allowed: " + mPendingCmds.size() +
    539                                 " >= " + mMaxCount);
    540                         // let any waiter timeout waiting for this
    541                         PendingCmd pendingCmd = mPendingCmds.remove();
    542                         Slog.e("NativeDaemonConnector.ResponseQueue",
    543                                 "Removing request: " + pendingCmd.logCmd + " (" +
    544                                 pendingCmd.cmdNum + ")");
    545                     }
    546                     found = new PendingCmd(cmdNum, null);
    547                     mPendingCmds.add(found);
    548                 }
    549                 found.availableResponseCount++;
    550                 // if a matching remove call has already retrieved this we can remove this
    551                 // instance from our list
    552                 if (found.availableResponseCount == 0) mPendingCmds.remove(found);
    553             }
    554             try {
    555                 found.responses.put(response);
    556             } catch (InterruptedException e) { }
    557         }
    558 
    559         // note that the timeout does not count time in deep sleep.  If you don't want
    560         // the device to sleep, hold a wakelock
    561         public NativeDaemonEvent remove(int cmdNum, int timeoutMs, String logCmd) {
    562             PendingCmd found = null;
    563             synchronized (mPendingCmds) {
    564                 for (PendingCmd pendingCmd : mPendingCmds) {
    565                     if (pendingCmd.cmdNum == cmdNum) {
    566                         found = pendingCmd;
    567                         break;
    568                     }
    569                 }
    570                 if (found == null) {
    571                     found = new PendingCmd(cmdNum, logCmd);
    572                     mPendingCmds.add(found);
    573                 }
    574                 found.availableResponseCount--;
    575                 // if a matching add call has already retrieved this we can remove this
    576                 // instance from our list
    577                 if (found.availableResponseCount == 0) mPendingCmds.remove(found);
    578             }
    579             NativeDaemonEvent result = null;
    580             try {
    581                 result = found.responses.poll(timeoutMs, TimeUnit.MILLISECONDS);
    582             } catch (InterruptedException e) {}
    583             if (result == null) {
    584                 Slog.e("NativeDaemonConnector.ResponseQueue", "Timeout waiting for response");
    585             }
    586             return result;
    587         }
    588 
    589         public void dump(FileDescriptor fd, PrintWriter pw, String[] args) {
    590             pw.println("Pending requests:");
    591             synchronized (mPendingCmds) {
    592                 for (PendingCmd pendingCmd : mPendingCmds) {
    593                     pw.println("  Cmd " + pendingCmd.cmdNum + " - " + pendingCmd.logCmd);
    594                 }
    595             }
    596         }
    597     }
    598 }
    599