1 /** 2 * Copyright (C) 2022 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.remoteprovisioner; 18 19 import android.content.Context; 20 import android.hardware.security.keymint.SecurityLevel; 21 import android.net.ConnectivityManager; 22 import android.net.NetworkCapabilities; 23 import android.os.SystemClock; 24 import android.os.SystemProperties; 25 import android.util.Log; 26 27 import java.time.Duration; 28 29 /** 30 * Contains the metrics values that are recorded for every attempt to remotely provision keys. 31 * This class will automatically push the atoms on close, and is intended to be used with a 32 * try-with-resources block to ensure metrics are automatically logged on completion of an attempt. 33 */ 34 public final class ProvisionerMetrics implements AutoCloseable { 35 // The state of remote provisioning enablement 36 public enum Enablement { 37 UNKNOWN, 38 ENABLED_WITH_FALLBACK, 39 ENABLED_RKP_ONLY, 40 DISABLED 41 } 42 43 public enum Status { 44 UNKNOWN, 45 KEYS_SUCCESSFULLY_PROVISIONED, 46 NO_PROVISIONING_NEEDED, 47 PROVISIONING_DISABLED, 48 INTERNAL_ERROR, 49 NO_NETWORK_CONNECTIVITY, 50 OUT_OF_ERROR_BUDGET, 51 INTERRUPTED, 52 GENERATE_KEYPAIR_FAILED, 53 GENERATE_CSR_FAILED, 54 GET_POOL_STATUS_FAILED, 55 INSERT_CHAIN_INTO_POOL_FAILED, 56 FETCH_GEEK_TIMED_OUT, 57 FETCH_GEEK_IO_EXCEPTION, 58 FETCH_GEEK_HTTP_ERROR, 59 SIGN_CERTS_TIMED_OUT, 60 SIGN_CERTS_IO_EXCEPTION, 61 SIGN_CERTS_HTTP_ERROR, 62 SIGN_CERTS_DEVICE_NOT_REGISTERED 63 } 64 65 /** 66 * Restartable stopwatch class that can be used to measure multiple start->stop time 67 * intervals. All measured time intervals are summed and returned by getElapsedMillis. 68 */ 69 public static class StopWatch implements AutoCloseable { 70 private long mStartTime = 0; 71 private long mElapsedTime = 0; 72 73 /** Start or resume a timer. */ start()74 public void start() { 75 if (isRunning()) { 76 Log.w(TAG, "Starting a timer that's already been running for " 77 + getElapsedMillis() + "ms"); 78 } else { 79 mStartTime = SystemClock.elapsedRealtime(); 80 } 81 } 82 83 /** Stop recording time. */ stop()84 public void stop() { 85 if (!isRunning()) { 86 Log.w(TAG, "Attempting to stop a timer that hasn't been started."); 87 } else { 88 mElapsedTime += SystemClock.elapsedRealtime() - mStartTime; 89 mStartTime = 0; 90 } 91 } 92 93 /** Stops the timer if it's running. */ 94 @Override close()95 public void close() { 96 if (isRunning()) { 97 stop(); 98 } 99 } 100 101 /** Get how long the timer has been recording. */ getElapsedMillis()102 public int getElapsedMillis() { 103 if (isRunning()) { 104 return (int) (mElapsedTime + SystemClock.elapsedRealtime() - mStartTime); 105 } else { 106 return (int) mElapsedTime; 107 } 108 } 109 110 /** Is the timer currently recording time? */ isRunning()111 public boolean isRunning() { 112 return mStartTime != 0; 113 } 114 } 115 116 private static final String TAG = Provisioner.TAG; 117 118 private final Context mContext; 119 private final int mCause; 120 private final StopWatch mServerWaitTimer = new StopWatch(); 121 private final StopWatch mBinderWaitTimer = new StopWatch(); 122 private final StopWatch mLockWaitTimer = new StopWatch(); 123 private final StopWatch mTotalTimer = new StopWatch(); 124 private final String mRemotelyProvisionedComponent; 125 private Enablement mEnablement; 126 private boolean mIsKeyPoolEmpty = false; 127 private Status mStatus = Status.UNKNOWN; 128 private int mHttpStatusError = 0; 129 ProvisionerMetrics(Context context, int cause, String remotelyProvisionedComponent, Enablement enablement)130 private ProvisionerMetrics(Context context, int cause, 131 String remotelyProvisionedComponent, Enablement enablement) { 132 mContext = context; 133 mCause = cause; 134 mRemotelyProvisionedComponent = remotelyProvisionedComponent; 135 mEnablement = enablement; 136 mTotalTimer.start(); 137 } 138 139 /** Start collecting metrics for scheduled provisioning. */ createScheduledAttemptMetrics(Context context)140 public static ProvisionerMetrics createScheduledAttemptMetrics(Context context) { 141 // Scheduled jobs (PeriodicProvisioner) intermix a lot of operations for multiple 142 // components, which makes it difficult to tease apart what is happening for which 143 // remotely provisioned component. Thus, on these calls, the component and 144 // component-specific enablement are not logged. 145 return new ProvisionerMetrics( 146 context, 147 RemoteProvisionerStatsLog.REMOTE_KEY_PROVISIONING_ATTEMPT__CAUSE__SCHEDULED, 148 "", 149 Enablement.UNKNOWN); 150 } 151 152 /** Start collecting metrics when an attestation key has been consumed from the pool. */ createKeyConsumedAttemptMetrics(Context context, int securityLevel)153 public static ProvisionerMetrics createKeyConsumedAttemptMetrics(Context context, 154 int securityLevel) { 155 return new ProvisionerMetrics( 156 context, 157 RemoteProvisionerStatsLog.REMOTE_KEY_PROVISIONING_ATTEMPT__CAUSE__KEY_CONSUMED, 158 getRemotelyProvisionedComponentName(securityLevel), 159 getEnablementForSecurityLevel(securityLevel)); 160 } 161 162 /** Start collecting metrics when the spare attestation key pool is empty. */ createOutOfKeysAttemptMetrics(Context context, int securityLevel)163 public static ProvisionerMetrics createOutOfKeysAttemptMetrics(Context context, 164 int securityLevel) { 165 return new ProvisionerMetrics( 166 context, 167 RemoteProvisionerStatsLog.REMOTE_KEY_PROVISIONING_ATTEMPT__CAUSE__OUT_OF_KEYS, 168 getRemotelyProvisionedComponentName(securityLevel), 169 getEnablementForSecurityLevel(securityLevel)); 170 } 171 172 /** Record the state of RKP configuration. */ setEnablement(Enablement enablement)173 public void setEnablement(Enablement enablement) { 174 mEnablement = enablement; 175 } 176 177 /** Set to true if the provisioning encountered an empty key pool. */ setIsKeyPoolEmpty(boolean isEmpty)178 public void setIsKeyPoolEmpty(boolean isEmpty) { 179 mIsKeyPoolEmpty = isEmpty; 180 } 181 182 /** Set the status for this provisioning attempt. */ setStatus(Status status)183 public void setStatus(Status status) { 184 mStatus = status; 185 } 186 187 /** Set the last HTTP status encountered. */ setHttpStatusError(int httpStatusError)188 public void setHttpStatusError(int httpStatusError) { 189 mHttpStatusError = httpStatusError; 190 } 191 192 /** 193 * Starts the server wait timer, returning a reference to an object to be closed when the 194 * wait is over. 195 */ startServerWait()196 public StopWatch startServerWait() { 197 mServerWaitTimer.start(); 198 return mServerWaitTimer; 199 } 200 201 /** 202 * Starts the binder wait timer, returning a reference to an object to be closed when the 203 * wait is over. 204 */ startBinderWait()205 public StopWatch startBinderWait() { 206 mBinderWaitTimer.start(); 207 return mBinderWaitTimer; 208 } 209 210 /** 211 * Starts the lock wait timer, returning a reference to an object to be closed when the 212 * wait is over. 213 */ startLockWait()214 public StopWatch startLockWait() { 215 mLockWaitTimer.start(); 216 return mLockWaitTimer; 217 } 218 219 /** Record the atoms for this metrics object. */ 220 @Override close()221 public void close() { 222 mTotalTimer.stop(); 223 224 int transportType = getTransportTypeForActiveNetwork(); 225 RemoteProvisionerStatsLog.write(RemoteProvisionerStatsLog.REMOTE_KEY_PROVISIONING_ATTEMPT, 226 mCause, mRemotelyProvisionedComponent, getUpTimeBucket(), getIntEnablement(), 227 mIsKeyPoolEmpty, getIntStatus()); 228 RemoteProvisionerStatsLog.write( 229 RemoteProvisionerStatsLog.REMOTE_KEY_PROVISIONING_NETWORK_INFO, 230 transportType, getIntStatus(), mHttpStatusError); 231 RemoteProvisionerStatsLog.write(RemoteProvisionerStatsLog.REMOTE_KEY_PROVISIONING_TIMING, 232 mServerWaitTimer.getElapsedMillis(), mBinderWaitTimer.getElapsedMillis(), 233 mLockWaitTimer.getElapsedMillis(), 234 mTotalTimer.getElapsedMillis(), transportType, mRemotelyProvisionedComponent); 235 } 236 237 // TODO: Fix this in U when the provisioner uses the remotely provisioned component names. getRemotelyProvisionedComponentName(int securityLevel)238 private static String getRemotelyProvisionedComponentName(int securityLevel) { 239 switch (securityLevel) { 240 case SecurityLevel.SOFTWARE: 241 return "SOFTWARE_KEYMINT"; 242 case SecurityLevel.TRUSTED_ENVIRONMENT: 243 return "TEE_KEYMINT"; 244 case SecurityLevel.STRONGBOX: 245 return "STRONGBOX"; 246 default: 247 return "UNKNOWN"; 248 } 249 } 250 getEnablementForSecurityLevel(int securityLevel)251 private static Enablement getEnablementForSecurityLevel(int securityLevel) { 252 switch (securityLevel) { 253 case SecurityLevel.SOFTWARE: 254 return Enablement.ENABLED_WITH_FALLBACK; 255 case SecurityLevel.TRUSTED_ENVIRONMENT: 256 return readRkpOnlyProperty("remote_provisioning.tee.rkp_only"); 257 case SecurityLevel.STRONGBOX: 258 return readRkpOnlyProperty("remote_provisioning.strongbox.rkp_only"); 259 default: 260 return Enablement.UNKNOWN; 261 } 262 } 263 readRkpOnlyProperty(String property)264 private static Enablement readRkpOnlyProperty(String property) { 265 if (SystemProperties.getBoolean(property, false)) { 266 return Enablement.ENABLED_RKP_ONLY; 267 } 268 return Enablement.ENABLED_WITH_FALLBACK; 269 } 270 getTransportTypeForActiveNetwork()271 private int getTransportTypeForActiveNetwork() { 272 ConnectivityManager cm = mContext.getSystemService(ConnectivityManager.class); 273 if (cm == null) { 274 Log.w(TAG, "Unable to get ConnectivityManager instance"); 275 return RemoteProvisionerStatsLog 276 .REMOTE_KEY_PROVISIONING_NETWORK_INFO__TRANSPORT_TYPE__TT_UNKNOWN; 277 } 278 279 NetworkCapabilities capabilities = cm.getNetworkCapabilities(cm.getActiveNetwork()); 280 if (capabilities == null) { 281 return RemoteProvisionerStatsLog 282 .REMOTE_KEY_PROVISIONING_NETWORK_INFO__TRANSPORT_TYPE__TT_UNKNOWN; 283 } 284 285 if (capabilities.hasTransport(NetworkCapabilities.TRANSPORT_VPN)) { 286 if (capabilities.hasTransport(NetworkCapabilities.TRANSPORT_CELLULAR) 287 && capabilities.hasTransport(NetworkCapabilities.TRANSPORT_WIFI)) { 288 return RemoteProvisionerStatsLog 289 .REMOTE_KEY_PROVISIONING_NETWORK_INFO__TRANSPORT_TYPE__TT_WIFI_CELLULAR_VPN; 290 } 291 if (capabilities.hasTransport(NetworkCapabilities.TRANSPORT_CELLULAR)) { 292 return RemoteProvisionerStatsLog 293 .REMOTE_KEY_PROVISIONING_NETWORK_INFO__TRANSPORT_TYPE__TT_CELLULAR_VPN; 294 } 295 if (capabilities.hasTransport(NetworkCapabilities.TRANSPORT_WIFI)) { 296 return RemoteProvisionerStatsLog 297 .REMOTE_KEY_PROVISIONING_NETWORK_INFO__TRANSPORT_TYPE__TT_WIFI_VPN; 298 } 299 if (capabilities.hasTransport(NetworkCapabilities.TRANSPORT_BLUETOOTH)) { 300 return RemoteProvisionerStatsLog 301 .REMOTE_KEY_PROVISIONING_NETWORK_INFO__TRANSPORT_TYPE__TT_BLUETOOTH_VPN; 302 } 303 if (capabilities.hasTransport(NetworkCapabilities.TRANSPORT_ETHERNET)) { 304 return RemoteProvisionerStatsLog 305 .REMOTE_KEY_PROVISIONING_NETWORK_INFO__TRANSPORT_TYPE__TT_ETHERNET_VPN; 306 } 307 return RemoteProvisionerStatsLog 308 .REMOTE_KEY_PROVISIONING_NETWORK_INFO__TRANSPORT_TYPE__TT_UNKNOWN; 309 } 310 311 if (capabilities.hasTransport(NetworkCapabilities.TRANSPORT_CELLULAR)) { 312 return RemoteProvisionerStatsLog 313 .REMOTE_KEY_PROVISIONING_NETWORK_INFO__TRANSPORT_TYPE__TT_CELLULAR; 314 } 315 if (capabilities.hasTransport(NetworkCapabilities.TRANSPORT_WIFI)) { 316 return RemoteProvisionerStatsLog 317 .REMOTE_KEY_PROVISIONING_NETWORK_INFO__TRANSPORT_TYPE__TT_WIFI; 318 } 319 if (capabilities.hasTransport(NetworkCapabilities.TRANSPORT_BLUETOOTH)) { 320 return RemoteProvisionerStatsLog 321 .REMOTE_KEY_PROVISIONING_NETWORK_INFO__TRANSPORT_TYPE__TT_BLUETOOTH; 322 } 323 if (capabilities.hasTransport(NetworkCapabilities.TRANSPORT_ETHERNET)) { 324 return RemoteProvisionerStatsLog 325 .REMOTE_KEY_PROVISIONING_NETWORK_INFO__TRANSPORT_TYPE__TT_ETHERNET; 326 } 327 if (capabilities.hasTransport(NetworkCapabilities.TRANSPORT_WIFI_AWARE)) { 328 return RemoteProvisionerStatsLog 329 .REMOTE_KEY_PROVISIONING_NETWORK_INFO__TRANSPORT_TYPE__TT_WIFI_AWARE; 330 } 331 if (capabilities.hasTransport(NetworkCapabilities.TRANSPORT_LOWPAN)) { 332 return RemoteProvisionerStatsLog 333 .REMOTE_KEY_PROVISIONING_NETWORK_INFO__TRANSPORT_TYPE__TT_LOWPAN; 334 } 335 336 return RemoteProvisionerStatsLog 337 .REMOTE_KEY_PROVISIONING_NETWORK_INFO__TRANSPORT_TYPE__TT_UNKNOWN; 338 } 339 getUpTimeBucket()340 private int getUpTimeBucket() { 341 final long uptimeMillis = SystemClock.uptimeMillis(); 342 if (uptimeMillis < Duration.ofMinutes(5).toMillis()) { 343 return RemoteProvisionerStatsLog 344 .REMOTE_KEY_PROVISIONING_ATTEMPT__UPTIME__LESS_THAN_5_MINUTES; 345 } else if (uptimeMillis < Duration.ofMinutes(60).toMillis()) { 346 return RemoteProvisionerStatsLog 347 .REMOTE_KEY_PROVISIONING_ATTEMPT__UPTIME__BETWEEN_5_AND_60_MINUTES; 348 } else { 349 return RemoteProvisionerStatsLog 350 .REMOTE_KEY_PROVISIONING_ATTEMPT__UPTIME__MORE_THAN_60_MINUTES; 351 } 352 } 353 getIntStatus()354 private int getIntStatus() { 355 switch (mStatus) { 356 // A whole bunch of generated types here just don't fit in our line length limit. 357 // CHECKSTYLE:OFF Generated code 358 case UNKNOWN: 359 return RemoteProvisionerStatsLog 360 .REMOTE_KEY_PROVISIONING_NETWORK_INFO__STATUS__REMOTE_KEY_PROVISIONING_STATUS_UNKNOWN; 361 case KEYS_SUCCESSFULLY_PROVISIONED: 362 return RemoteProvisionerStatsLog 363 .REMOTE_KEY_PROVISIONING_NETWORK_INFO__STATUS__KEYS_SUCCESSFULLY_PROVISIONED; 364 case NO_PROVISIONING_NEEDED: 365 return RemoteProvisionerStatsLog 366 .REMOTE_KEY_PROVISIONING_NETWORK_INFO__STATUS__NO_PROVISIONING_NEEDED; 367 case PROVISIONING_DISABLED: 368 return RemoteProvisionerStatsLog 369 .REMOTE_KEY_PROVISIONING_NETWORK_INFO__STATUS__PROVISIONING_DISABLED; 370 case INTERNAL_ERROR: 371 return RemoteProvisionerStatsLog 372 .REMOTE_KEY_PROVISIONING_NETWORK_INFO__STATUS__INTERNAL_ERROR; 373 case NO_NETWORK_CONNECTIVITY: 374 return RemoteProvisionerStatsLog 375 .REMOTE_KEY_PROVISIONING_NETWORK_INFO__STATUS__NO_NETWORK_CONNECTIVITY; 376 case OUT_OF_ERROR_BUDGET: 377 return RemoteProvisionerStatsLog 378 .REMOTE_KEY_PROVISIONING_NETWORK_INFO__STATUS__OUT_OF_ERROR_BUDGET; 379 case INTERRUPTED: 380 return RemoteProvisionerStatsLog 381 .REMOTE_KEY_PROVISIONING_NETWORK_INFO__STATUS__INTERRUPTED; 382 case GENERATE_KEYPAIR_FAILED: 383 return RemoteProvisionerStatsLog 384 .REMOTE_KEY_PROVISIONING_NETWORK_INFO__STATUS__GENERATE_KEYPAIR_FAILED; 385 case GENERATE_CSR_FAILED: 386 return RemoteProvisionerStatsLog 387 .REMOTE_KEY_PROVISIONING_NETWORK_INFO__STATUS__GENERATE_CSR_FAILED; 388 case GET_POOL_STATUS_FAILED: 389 return RemoteProvisionerStatsLog 390 .REMOTE_KEY_PROVISIONING_NETWORK_INFO__STATUS__GET_POOL_STATUS_FAILED; 391 case INSERT_CHAIN_INTO_POOL_FAILED: 392 return RemoteProvisionerStatsLog 393 .REMOTE_KEY_PROVISIONING_NETWORK_INFO__STATUS__INSERT_CHAIN_INTO_POOL_FAILED; 394 case FETCH_GEEK_TIMED_OUT: 395 return RemoteProvisionerStatsLog 396 .REMOTE_KEY_PROVISIONING_NETWORK_INFO__STATUS__FETCH_GEEK_TIMED_OUT; 397 case FETCH_GEEK_IO_EXCEPTION: 398 return RemoteProvisionerStatsLog 399 .REMOTE_KEY_PROVISIONING_NETWORK_INFO__STATUS__FETCH_GEEK_IO_EXCEPTION; 400 case FETCH_GEEK_HTTP_ERROR: 401 return RemoteProvisionerStatsLog 402 .REMOTE_KEY_PROVISIONING_NETWORK_INFO__STATUS__FETCH_GEEK_HTTP_ERROR; 403 case SIGN_CERTS_TIMED_OUT: 404 return RemoteProvisionerStatsLog 405 .REMOTE_KEY_PROVISIONING_NETWORK_INFO__STATUS__SIGN_CERTS_TIMED_OUT; 406 case SIGN_CERTS_IO_EXCEPTION: 407 return RemoteProvisionerStatsLog 408 .REMOTE_KEY_PROVISIONING_NETWORK_INFO__STATUS__SIGN_CERTS_IO_EXCEPTION; 409 case SIGN_CERTS_HTTP_ERROR: 410 return RemoteProvisionerStatsLog 411 .REMOTE_KEY_PROVISIONING_NETWORK_INFO__STATUS__SIGN_CERTS_HTTP_ERROR; 412 case SIGN_CERTS_DEVICE_NOT_REGISTERED: 413 return RemoteProvisionerStatsLog 414 .REMOTE_KEY_PROVISIONING_NETWORK_INFO__STATUS__SIGN_CERTS_DEVICE_NOT_REGISTERED; 415 } 416 return RemoteProvisionerStatsLog 417 .REMOTE_KEY_PROVISIONING_NETWORK_INFO__STATUS__REMOTE_KEY_PROVISIONING_STATUS_UNKNOWN; 418 // CHECKSTYLE:ON Generated code 419 } 420 getIntEnablement()421 private int getIntEnablement() { 422 switch (mEnablement) { 423 case UNKNOWN: 424 return RemoteProvisionerStatsLog 425 .REMOTE_KEY_PROVISIONING_ATTEMPT__ENABLEMENT__ENABLEMENT_UNKNOWN; 426 case ENABLED_WITH_FALLBACK: 427 return RemoteProvisionerStatsLog 428 .REMOTE_KEY_PROVISIONING_ATTEMPT__ENABLEMENT__ENABLED_WITH_FALLBACK; 429 case ENABLED_RKP_ONLY: 430 return RemoteProvisionerStatsLog 431 .REMOTE_KEY_PROVISIONING_ATTEMPT__ENABLEMENT__ENABLED_RKP_ONLY; 432 case DISABLED: 433 return RemoteProvisionerStatsLog 434 .REMOTE_KEY_PROVISIONING_ATTEMPT__ENABLEMENT__DISABLED; 435 } 436 return RemoteProvisionerStatsLog 437 .REMOTE_KEY_PROVISIONING_ATTEMPT__ENABLEMENT__ENABLEMENT_UNKNOWN; 438 } 439 } 440