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