diff options
| author | 2022-08-16 11:47:49 +0000 | |
|---|---|---|
| committer | 2022-08-16 11:47:49 +0000 | |
| commit | e076854f74cc30af709bee6d2171ce499496dbc4 (patch) | |
| tree | e9576a2ed4c2c80da32aefd2f0674cc13352fe12 | |
| parent | 5a54deb0091d57b7a62c6bb94bb83b181316fe90 (diff) | |
| parent | b8674b79c8d8b2a0f8417d38f95ebf371f29ddc7 (diff) | |
Merge "Collect VibrationReported metrics" into tm-qpr-dev
18 files changed, 1645 insertions, 261 deletions
diff --git a/core/proto/android/server/vibrator/vibratormanagerservice.proto b/core/proto/android/server/vibrator/vibratormanagerservice.proto index 2a625b027c17..25a1f68a0afe 100644 --- a/core/proto/android/server/vibrator/vibratormanagerservice.proto +++ b/core/proto/android/server/vibrator/vibratormanagerservice.proto @@ -86,7 +86,7 @@ message VibrationAttributesProto { optional int32 flags = 3; } -// Next id: 8 +// Next Tag: 9 message VibrationProto { option (.android.msg_privacy).dest = DEST_AUTOMATIC; optional int64 start_time = 1; @@ -94,11 +94,43 @@ message VibrationProto { optional CombinedVibrationEffectProto effect = 3; optional CombinedVibrationEffectProto original_effect = 4; optional VibrationAttributesProto attributes = 5; - optional int32 status = 6; optional int64 duration_ms = 7; + optional Status status = 8; + reserved 6; // prev int32 status + + // Also used by VibrationReported from frameworks/proto_logging/stats/atoms.proto. + // Next Tag: 26 + enum Status { + UNKNOWN = 0; + RUNNING = 1; + FINISHED = 2; + FINISHED_UNEXPECTED = 3; // Didn't terminate in the usual way. + FORWARDED_TO_INPUT_DEVICES = 4; + CANCELLED_BINDER_DIED = 5; + CANCELLED_BY_SCREEN_OFF = 6; + CANCELLED_BY_SETTINGS_UPDATE = 7; + CANCELLED_BY_USER = 8; + CANCELLED_BY_UNKNOWN_REASON = 9; + CANCELLED_SUPERSEDED = 10; + IGNORED_ERROR_APP_OPS = 11; + IGNORED_ERROR_CANCELLING = 12; + IGNORED_ERROR_SCHEDULING = 13; + IGNORED_ERROR_TOKEN= 14; + IGNORED_APP_OPS = 15; + IGNORED_BACKGROUND = 16; + IGNORED_UNKNOWN_VIBRATION = 17; + IGNORED_UNSUPPORTED = 18; + IGNORED_FOR_EXTERNAL = 19; + IGNORED_FOR_HIGHER_IMPORTANCE = 20; + IGNORED_FOR_ONGOING = 21; + IGNORED_FOR_POWER = 22; + IGNORED_FOR_RINGER_MODE = 23; + IGNORED_FOR_SETTINGS = 24; + IGNORED_SUPERSEDED = 25; + } } -// Next id: 25 +// Next Tag: 25 message VibratorManagerServiceDumpProto { option (.android.msg_privacy).dest = DEST_AUTOMATIC; repeated int32 vibrator_ids = 1; diff --git a/services/core/java/com/android/server/vibrator/AbstractVibratorStep.java b/services/core/java/com/android/server/vibrator/AbstractVibratorStep.java index 12e68b10c3df..eebd046b2601 100644 --- a/services/core/java/com/android/server/vibrator/AbstractVibratorStep.java +++ b/services/core/java/com/android/server/vibrator/AbstractVibratorStep.java @@ -96,6 +96,7 @@ abstract class AbstractVibratorStep extends Step { "Turning off vibrator " + getVibratorId()); } controller.off(); + getVibration().stats().reportVibratorOff(); } protected void changeAmplitude(float amplitude) { @@ -104,6 +105,7 @@ abstract class AbstractVibratorStep extends Step { "Amplitude changed on vibrator " + getVibratorId() + " to " + amplitude); } controller.setAmplitude(amplitude); + getVibration().stats().reportSetAmplitude(); } /** @@ -147,6 +149,8 @@ abstract class AbstractVibratorStep extends Step { if (nextSegmentIndex >= effectSize && repeatIndex >= 0) { // Count the loops that were played. int loopSize = effectSize - repeatIndex; + int loopSegmentsPlayed = nextSegmentIndex - repeatIndex; + getVibration().stats().reportRepetition(loopSegmentsPlayed / loopSize); nextSegmentIndex = repeatIndex + ((nextSegmentIndex - effectSize) % loopSize); } Step nextStep = conductor.nextVibrateStep(nextStartTime, controller, effect, diff --git a/services/core/java/com/android/server/vibrator/ComposePrimitivesVibratorStep.java b/services/core/java/com/android/server/vibrator/ComposePrimitivesVibratorStep.java index 3bc11c8f8322..f8b99265246a 100644 --- a/services/core/java/com/android/server/vibrator/ComposePrimitivesVibratorStep.java +++ b/services/core/java/com/android/server/vibrator/ComposePrimitivesVibratorStep.java @@ -67,9 +67,10 @@ final class ComposePrimitivesVibratorStep extends AbstractVibratorStep { Slog.d(VibrationThread.TAG, "Compose " + primitives + " primitives on vibrator " + controller.getVibratorInfo().getId()); } - mVibratorOnResult = controller.on( - primitives.toArray(new PrimitiveSegment[primitives.size()]), - getVibration().id); + PrimitiveSegment[] primitivesArray = + primitives.toArray(new PrimitiveSegment[primitives.size()]); + mVibratorOnResult = controller.on(primitivesArray, getVibration().id); + getVibration().stats().reportComposePrimitives(mVibratorOnResult, primitivesArray); return nextSteps(/* segmentsPlayed= */ primitives.size()); } finally { diff --git a/services/core/java/com/android/server/vibrator/ComposePwleVibratorStep.java b/services/core/java/com/android/server/vibrator/ComposePwleVibratorStep.java index 919f1be27ef9..81f52c912f28 100644 --- a/services/core/java/com/android/server/vibrator/ComposePwleVibratorStep.java +++ b/services/core/java/com/android/server/vibrator/ComposePwleVibratorStep.java @@ -68,8 +68,9 @@ final class ComposePwleVibratorStep extends AbstractVibratorStep { Slog.d(VibrationThread.TAG, "Compose " + pwles + " PWLEs on vibrator " + controller.getVibratorInfo().getId()); } - mVibratorOnResult = controller.on(pwles.toArray(new RampSegment[pwles.size()]), - getVibration().id); + RampSegment[] pwlesArray = pwles.toArray(new RampSegment[pwles.size()]); + mVibratorOnResult = controller.on(pwlesArray, getVibration().id); + getVibration().stats().reportComposePwle(mVibratorOnResult, pwlesArray); return nextSteps(/* segmentsPlayed= */ pwles.size()); } finally { diff --git a/services/core/java/com/android/server/vibrator/PerformPrebakedVibratorStep.java b/services/core/java/com/android/server/vibrator/PerformPrebakedVibratorStep.java index 601ae978f637..41902147838d 100644 --- a/services/core/java/com/android/server/vibrator/PerformPrebakedVibratorStep.java +++ b/services/core/java/com/android/server/vibrator/PerformPrebakedVibratorStep.java @@ -62,6 +62,7 @@ final class PerformPrebakedVibratorStep extends AbstractVibratorStep { VibrationEffect fallback = getVibration().getFallback(prebaked.getEffectId()); mVibratorOnResult = controller.on(prebaked, getVibration().id); + getVibration().stats().reportPerformEffect(mVibratorOnResult, prebaked); if (mVibratorOnResult == 0 && prebaked.shouldFallback() && (fallback instanceof VibrationEffect.Composed)) { diff --git a/services/core/java/com/android/server/vibrator/SetAmplitudeVibratorStep.java b/services/core/java/com/android/server/vibrator/SetAmplitudeVibratorStep.java index 1f0d2d71d25c..6fb9111793ea 100644 --- a/services/core/java/com/android/server/vibrator/SetAmplitudeVibratorStep.java +++ b/services/core/java/com/android/server/vibrator/SetAmplitudeVibratorStep.java @@ -148,7 +148,9 @@ final class SetAmplitudeVibratorStep extends AbstractVibratorStep { "Turning on vibrator " + controller.getVibratorInfo().getId() + " for " + duration + "ms"); } - return controller.on(duration, getVibration().id); + long vibratorOnResult = controller.on(duration, getVibration().id); + getVibration().stats().reportVibratorOn(vibratorOnResult); + return vibratorOnResult; } /** diff --git a/services/core/java/com/android/server/vibrator/StartSequentialEffectStep.java b/services/core/java/com/android/server/vibrator/StartSequentialEffectStep.java index 080a36cb2a6e..2c6fbbc945fa 100644 --- a/services/core/java/com/android/server/vibrator/StartSequentialEffectStep.java +++ b/services/core/java/com/android/server/vibrator/StartSequentialEffectStep.java @@ -93,10 +93,8 @@ final class StartSequentialEffectStep extends Step { } mVibratorsOnMaxDuration = startVibrating(effectMapping, nextSteps); - if (mVibratorsOnMaxDuration > 0) { - conductor.vibratorManagerHooks.noteVibratorOn(conductor.getVibration().uid, - mVibratorsOnMaxDuration); - } + conductor.vibratorManagerHooks.noteVibratorOn(conductor.getVibration().uid, + mVibratorsOnMaxDuration); } finally { if (mVibratorsOnMaxDuration >= 0) { // It least one vibrator was started then add a finish step to wait for all diff --git a/services/core/java/com/android/server/vibrator/Vibration.java b/services/core/java/com/android/server/vibrator/Vibration.java index d79837be3583..a375d0aceb54 100644 --- a/services/core/java/com/android/server/vibrator/Vibration.java +++ b/services/core/java/com/android/server/vibrator/Vibration.java @@ -16,10 +16,10 @@ package com.android.server.vibrator; +import android.annotation.NonNull; import android.annotation.Nullable; import android.os.CombinedVibration; import android.os.IBinder; -import android.os.SystemClock; import android.os.VibrationAttributes; import android.os.VibrationEffect; import android.os.vibrator.PrebakedSegment; @@ -30,48 +30,60 @@ import android.os.vibrator.VibrationEffectSegment; import android.util.SparseArray; import android.util.proto.ProtoOutputStream; +import com.android.internal.util.FrameworkStatsLog; + import java.text.SimpleDateFormat; import java.util.Date; import java.util.List; +import java.util.Objects; import java.util.concurrent.CountDownLatch; import java.util.function.Function; /** Represents a vibration request to the vibrator service. */ final class Vibration { - private static final String TAG = "Vibration"; private static final SimpleDateFormat DEBUG_DATE_FORMAT = new SimpleDateFormat("MM-dd HH:mm:ss.SSS"); + /** Vibration status with reference to values from vibratormanagerservice.proto for logging. */ enum Status { - RUNNING, - FINISHED, - FINISHED_UNEXPECTED, // Didn't terminate in the usual way. - FORWARDED_TO_INPUT_DEVICES, - CANCELLED_BINDER_DIED, - CANCELLED_BY_SCREEN_OFF, - CANCELLED_BY_SETTINGS_UPDATE, - CANCELLED_BY_USER, - CANCELLED_BY_UNKNOWN_REASON, - CANCELLED_SUPERSEDED, - IGNORED_ERROR_APP_OPS, - IGNORED_ERROR_CANCELLING, - IGNORED_ERROR_SCHEDULING, - IGNORED_ERROR_TOKEN, - IGNORED_APP_OPS, - IGNORED_BACKGROUND, - IGNORED_UNKNOWN_VIBRATION, - IGNORED_UNSUPPORTED, - IGNORED_FOR_EXTERNAL, - IGNORED_FOR_HIGHER_IMPORTANCE, - IGNORED_FOR_ONGOING, - IGNORED_FOR_POWER, - IGNORED_FOR_RINGER_MODE, - IGNORED_FOR_SETTINGS, - IGNORED_SUPERSEDED, + UNKNOWN(VibrationProto.UNKNOWN), + RUNNING(VibrationProto.RUNNING), + FINISHED(VibrationProto.FINISHED), + FINISHED_UNEXPECTED(VibrationProto.FINISHED_UNEXPECTED), + FORWARDED_TO_INPUT_DEVICES(VibrationProto.FORWARDED_TO_INPUT_DEVICES), + CANCELLED_BINDER_DIED(VibrationProto.CANCELLED_BINDER_DIED), + CANCELLED_BY_SCREEN_OFF(VibrationProto.CANCELLED_BY_SCREEN_OFF), + CANCELLED_BY_SETTINGS_UPDATE(VibrationProto.CANCELLED_BY_SETTINGS_UPDATE), + CANCELLED_BY_USER(VibrationProto.CANCELLED_BY_USER), + CANCELLED_BY_UNKNOWN_REASON(VibrationProto.CANCELLED_BY_UNKNOWN_REASON), + CANCELLED_SUPERSEDED(VibrationProto.CANCELLED_SUPERSEDED), + IGNORED_ERROR_APP_OPS(VibrationProto.IGNORED_ERROR_APP_OPS), + IGNORED_ERROR_CANCELLING(VibrationProto.IGNORED_ERROR_CANCELLING), + IGNORED_ERROR_SCHEDULING(VibrationProto.IGNORED_ERROR_SCHEDULING), + IGNORED_ERROR_TOKEN(VibrationProto.IGNORED_ERROR_TOKEN), + IGNORED_APP_OPS(VibrationProto.IGNORED_APP_OPS), + IGNORED_BACKGROUND(VibrationProto.IGNORED_BACKGROUND), + IGNORED_UNKNOWN_VIBRATION(VibrationProto.IGNORED_UNKNOWN_VIBRATION), + IGNORED_UNSUPPORTED(VibrationProto.IGNORED_UNSUPPORTED), + IGNORED_FOR_EXTERNAL(VibrationProto.IGNORED_FOR_EXTERNAL), + IGNORED_FOR_HIGHER_IMPORTANCE(VibrationProto.IGNORED_FOR_HIGHER_IMPORTANCE), + IGNORED_FOR_ONGOING(VibrationProto.IGNORED_FOR_ONGOING), + IGNORED_FOR_POWER(VibrationProto.IGNORED_FOR_POWER), + IGNORED_FOR_RINGER_MODE(VibrationProto.IGNORED_FOR_RINGER_MODE), + IGNORED_FOR_SETTINGS(VibrationProto.IGNORED_FOR_SETTINGS), + IGNORED_SUPERSEDED(VibrationProto.IGNORED_SUPERSEDED); + + private final int mProtoEnumValue; + + Status(int value) { + mProtoEnumValue = value; + } + + public int getProtoEnumValue() { + return mProtoEnumValue; + } } - /** Start time using {@link SystemClock#uptimeMillis()}, for calculations. */ - public final long startUptimeMillis; public final VibrationAttributes attrs; public final long id; public final int uid; @@ -91,17 +103,11 @@ final class Vibration { @Nullable private CombinedVibration mOriginalEffect; - /** - * Start/end times in unix epoch time. Only to be used for debugging purposes and to correlate - * with other system events, any duration calculations should be done use - * {@link #startUptimeMillis} so as not to be affected by discontinuities created by RTC - * adjustments. - */ - private final long mStartTimeDebug; - private long mEndTimeDebug; - /** End time using {@link SystemClock#uptimeMillis()}, for calculations. */ - private long mEndUptimeMillis; - private Status mStatus; + /** Vibration status. */ + private Vibration.Status mStatus; + + /** Vibration runtime stats. */ + private final VibrationStats mStats = new VibrationStats(); /** A {@link CountDownLatch} to enable waiting for completion. */ private final CountDownLatch mCompletionLatch = new CountDownLatch(1); @@ -111,34 +117,35 @@ final class Vibration { this.token = token; this.mEffect = effect; this.id = id; - this.startUptimeMillis = SystemClock.uptimeMillis(); this.attrs = attrs; this.uid = uid; this.opPkg = opPkg; this.reason = reason; - mStartTimeDebug = System.currentTimeMillis(); - mStatus = Status.RUNNING; + mStatus = Vibration.Status.RUNNING; + } + + VibrationStats stats() { + return mStats; } /** - * Set the {@link Status} of this vibration and the current system time as this + * Set the {@link Status} of this vibration and reports the current system time as this * vibration end time, for debugging purposes. * * <p>This method will only accept given value if the current status is {@link * Status#RUNNING}. */ - public void end(Status status) { + public void end(EndInfo info) { if (hasEnded()) { // Vibration already ended, keep first ending status set and ignore this one. return; } - mStatus = status; - mEndUptimeMillis = SystemClock.uptimeMillis(); - mEndTimeDebug = System.currentTimeMillis(); + mStatus = info.status; + mStats.reportEnded(info.endedByUid, info.endedByUsage); mCompletionLatch.countDown(); } - /** Waits indefinitely until another thread calls {@link #end(Status)} on this vibration. */ + /** Waits indefinitely until another thread calls {@link #end} on this vibration. */ public void waitForEnd() throws InterruptedException { mCompletionLatch.await(); } @@ -228,16 +235,69 @@ final class Vibration { /** Return {@link Vibration.DebugInfo} with read-only debug information about this vibration. */ public Vibration.DebugInfo getDebugInfo() { - long durationMs = hasEnded() ? mEndUptimeMillis - startUptimeMillis : -1; - return new Vibration.DebugInfo( - mStartTimeDebug, mEndTimeDebug, durationMs, mEffect, mOriginalEffect, - /* scale= */ 0, attrs, uid, opPkg, reason, mStatus); + return new Vibration.DebugInfo(mStatus, mStats, mEffect, mOriginalEffect, /* scale= */ 0, + attrs, uid, opPkg, reason); + } + + /** Return {@link VibrationStats.StatsInfo} with read-only metrics about this vibration. */ + public VibrationStats.StatsInfo getStatsInfo(long completionUptimeMillis) { + int vibrationType = isRepeating() + ? FrameworkStatsLog.VIBRATION_REPORTED__VIBRATION_TYPE__REPEATED + : FrameworkStatsLog.VIBRATION_REPORTED__VIBRATION_TYPE__SINGLE; + return new VibrationStats.StatsInfo( + uid, vibrationType, attrs.getUsage(), mStatus, mStats, completionUptimeMillis); + } + + /** Immutable info passed as a signal to end a vibration. */ + static final class EndInfo { + /** The {@link Status} to be set to the vibration when it ends with this info. */ + @NonNull + public final Status status; + /** The UID that triggered the vibration that ended this, or -1 if undefined. */ + public final int endedByUid; + /** The VibrationAttributes.USAGE_* of the vibration that ended this, or -1 if undefined. */ + public final int endedByUsage; + + EndInfo(@NonNull Vibration.Status status) { + this(status, /* endedByUid= */ -1, /* endedByUsage= */ -1); + } + + EndInfo(@NonNull Vibration.Status status, int endedByUid, int endedByUsage) { + this.status = status; + this.endedByUid = endedByUid; + this.endedByUsage = endedByUsage; + } + + @Override + public boolean equals(Object o) { + if (this == o) return true; + if (!(o instanceof EndInfo)) return false; + EndInfo that = (EndInfo) o; + return endedByUid == that.endedByUid + && endedByUsage == that.endedByUsage + && status == that.status; + } + + @Override + public int hashCode() { + return Objects.hash(status, endedByUid, endedByUsage); + } + + @Override + public String toString() { + return "EndInfo{" + + "status=" + status + + ", endedByUid=" + endedByUid + + ", endedByUsage=" + endedByUsage + + '}'; + } } /** Debug information about vibrations. */ static final class DebugInfo { - private final long mStartTimeDebug; - private final long mEndTimeDebug; + private final long mCreateTime; + private final long mStartTime; + private final long mEndTime; private final long mDurationMs; private final CombinedVibration mEffect; private final CombinedVibration mOriginalEffect; @@ -248,12 +308,13 @@ final class Vibration { private final String mReason; private final Status mStatus; - DebugInfo(long startTimeDebug, long endTimeDebug, long durationMs, - CombinedVibration effect, CombinedVibration originalEffect, float scale, - VibrationAttributes attrs, int uid, String opPkg, String reason, Status status) { - mStartTimeDebug = startTimeDebug; - mEndTimeDebug = endTimeDebug; - mDurationMs = durationMs; + DebugInfo(Status status, VibrationStats stats, @Nullable CombinedVibration effect, + @Nullable CombinedVibration originalEffect, float scale, VibrationAttributes attrs, + int uid, String opPkg, String reason) { + mCreateTime = stats.getCreateTimeDebug(); + mStartTime = stats.getStartTimeDebug(); + mEndTime = stats.getEndTimeDebug(); + mDurationMs = stats.getDurationDebug(); mEffect = effect; mOriginalEffect = originalEffect; mScale = scale; @@ -267,11 +328,13 @@ final class Vibration { @Override public String toString() { return new StringBuilder() - .append("startTime: ") - .append(DEBUG_DATE_FORMAT.format(new Date(mStartTimeDebug))) + .append("createTime: ") + .append(DEBUG_DATE_FORMAT.format(new Date(mCreateTime))) + .append(", startTime: ") + .append(DEBUG_DATE_FORMAT.format(new Date(mStartTime))) .append(", endTime: ") - .append(mEndTimeDebug == 0 ? null - : DEBUG_DATE_FORMAT.format(new Date(mEndTimeDebug))) + .append(mEndTime == 0 ? null + : DEBUG_DATE_FORMAT.format(new Date(mEndTime))) .append(", durationMs: ") .append(mDurationMs) .append(", status: ") @@ -296,8 +359,8 @@ final class Vibration { /** Write this info into given {@code fieldId} on {@link ProtoOutputStream}. */ public void dumpProto(ProtoOutputStream proto, long fieldId) { final long token = proto.start(fieldId); - proto.write(VibrationProto.START_TIME, mStartTimeDebug); - proto.write(VibrationProto.END_TIME, mEndTimeDebug); + proto.write(VibrationProto.START_TIME, mStartTime); + proto.write(VibrationProto.END_TIME, mEndTime); proto.write(VibrationProto.DURATION_MS, mDurationMs); proto.write(VibrationProto.STATUS, mStatus.ordinal()); @@ -421,4 +484,5 @@ final class Vibration { proto.end(token); } } + } diff --git a/services/core/java/com/android/server/vibrator/VibrationStats.java b/services/core/java/com/android/server/vibrator/VibrationStats.java new file mode 100644 index 000000000000..931be1d5d711 --- /dev/null +++ b/services/core/java/com/android/server/vibrator/VibrationStats.java @@ -0,0 +1,395 @@ +/* + * Copyright (C) 2022 The Android Open Source Project + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +package com.android.server.vibrator; + +import android.os.SystemClock; +import android.os.vibrator.PrebakedSegment; +import android.os.vibrator.PrimitiveSegment; +import android.os.vibrator.RampSegment; +import android.util.Slog; +import android.util.SparseBooleanArray; + +import com.android.internal.annotations.VisibleForTesting; +import com.android.internal.util.FrameworkStatsLog; + +/** Holds basic stats about the vibration playback and interaction with the vibrator HAL. */ +final class VibrationStats { + static final String TAG = "VibrationStats"; + + // Milestone timestamps, using SystemClock.uptimeMillis(), for calculations. + // - Create: time a vibration object was created, which is closer to when the service receives a + // vibrate request. + // - Start: time a vibration started to play, which is closer to the time that the + // VibrationEffect started playing the very first segment. + // - End: time a vibration ended, even if it never started to play. This can be as soon as the + // vibrator HAL reports it has finished the last command, or before it has even started + // when the vibration is ignored or cancelled. + // Create and end times set by VibratorManagerService only, guarded by its lock. + // Start times set by VibrationThread only (single-threaded). + private long mCreateUptimeMillis; + private long mStartUptimeMillis; + private long mEndUptimeMillis; + + // Milestone timestamps, using unix epoch time, only to be used for debugging purposes and + // to correlate with other system events. Any duration calculations should be done with the + // {create/start/end}UptimeMillis counterparts so as not to be affected by discontinuities + // created by RTC adjustments. + // Set together with the *UptimeMillis counterparts. + private long mCreateTimeDebug; + private long mStartTimeDebug; + private long mEndTimeDebug; + + // Vibration interruption tracking. + // Set by VibratorManagerService only, guarded by its lock. + private int mEndedByUid; + private int mEndedByUsage; + private int mInterruptedUsage; + + // All following counters are set by VibrationThread only (single-threaded): + // Counts how many times the VibrationEffect was repeated. + private int mRepeatCount; + // Total duration, in milliseconds, the vibrator was active with non-zero amplitude. + private int mVibratorOnTotalDurationMillis; + // Total number of primitives used in compositions. + private int mVibrationCompositionTotalSize; + private int mVibrationPwleTotalSize; + // Counts how many times each IVibrator method was triggered by this vibration. + private int mVibratorOnCount; + private int mVibratorOffCount; + private int mVibratorSetAmplitudeCount; + private int mVibratorSetExternalControlCount; + private int mVibratorPerformCount; + private int mVibratorComposeCount; + private int mVibratorComposePwleCount; + + // Ids of vibration effects and primitives used by this vibration, with support flag. + // Set by VibrationThread only (single-threaded). + private SparseBooleanArray mVibratorEffectsUsed = new SparseBooleanArray(); + private SparseBooleanArray mVibratorPrimitivesUsed = new SparseBooleanArray(); + + VibrationStats() { + mCreateUptimeMillis = SystemClock.uptimeMillis(); + mCreateTimeDebug = System.currentTimeMillis(); + // Set invalid UID and VibrationAttributes.USAGE values to indicate fields are unset. + mEndedByUid = -1; + mEndedByUsage = -1; + mInterruptedUsage = -1; + } + + long getCreateUptimeMillis() { + return mCreateUptimeMillis; + } + + long getStartUptimeMillis() { + return mStartUptimeMillis; + } + + long getEndUptimeMillis() { + return mEndUptimeMillis; + } + + long getCreateTimeDebug() { + return mCreateTimeDebug; + } + + long getStartTimeDebug() { + return mStartTimeDebug; + } + + long getEndTimeDebug() { + return mEndTimeDebug; + } + + /** + * Duration calculated for debugging purposes, between the creation of a vibration and the + * end time being reported, or -1 if the vibration has not ended. + */ + long getDurationDebug() { + return hasEnded() ? (mEndUptimeMillis - mCreateUptimeMillis) : -1; + } + + /** Return true if vibration reported it has ended. */ + boolean hasEnded() { + return mEndUptimeMillis > 0; + } + + /** Return true if vibration reported it has started triggering the vibrator. */ + boolean hasStarted() { + return mStartUptimeMillis > 0; + } + + /** + * Set the current system time as this vibration start time, for debugging purposes. + * + * <p>This indicates the vibration has started to interact with the vibrator HAL and the + * device may start vibrating after this point. + * + * <p>This method will only accept given value if the start timestamp was never set. + */ + void reportStarted() { + if (hasEnded() || (mStartUptimeMillis != 0)) { + // Vibration already started or ended, keep first time set and ignore this one. + return; + } + mStartUptimeMillis = SystemClock.uptimeMillis(); + mStartTimeDebug = System.currentTimeMillis(); + } + + /** + * Set status and end cause for this vibration to end, and the current system time as this + * vibration end time, for debugging purposes. + * + * <p>This might be triggered before {@link #reportStarted()}, which indicates this + * vibration was cancelled or ignored before it started triggering the vibrator. + * + * @return true if the status was accepted. This method will only accept given values if + * the end timestamp was never set. + */ + boolean reportEnded(int endedByUid, int endedByUsage) { + if (hasEnded()) { + // Vibration already ended, keep first ending stats set and ignore this one. + return false; + } + mEndedByUid = endedByUid; + mEndedByUsage = endedByUsage; + mEndUptimeMillis = SystemClock.uptimeMillis(); + mEndTimeDebug = System.currentTimeMillis(); + return true; + } + + /** + * Report this vibration has interrupted another vibration. + * + * <p>This method will only accept the first value as the one that was interrupted by this + * vibration, and will ignore all successive calls. + */ + void reportInterruptedAnotherVibration(int interruptedUsage) { + if (mInterruptedUsage < 0) { + mInterruptedUsage = interruptedUsage; + } + } + + /** Report the vibration has looped a few more times. */ + void reportRepetition(int loops) { + mRepeatCount += loops; + } + + /** Report a call to vibrator method to turn on for given duration. */ + void reportVibratorOn(long halResult) { + mVibratorOnCount++; + + if (halResult > 0) { + // If HAL result is positive then it represents the actual duration it will be ON. + mVibratorOnTotalDurationMillis += (int) halResult; + } + } + + /** Report a call to vibrator method to turn off. */ + void reportVibratorOff() { + mVibratorOffCount++; + } + + /** Report a call to vibrator method to change the vibration amplitude. */ + void reportSetAmplitude() { + mVibratorSetAmplitudeCount++; + } + + /** Report a call to vibrator method to trigger a vibration effect. */ + void reportPerformEffect(long halResult, PrebakedSegment prebaked) { + mVibratorPerformCount++; + + if (halResult > 0) { + // If HAL result is positive then it represents the actual duration of the vibration. + mVibratorEffectsUsed.put(prebaked.getEffectId(), true); + mVibratorOnTotalDurationMillis += (int) halResult; + } else { + // Effect unsupported or request failed. + mVibratorEffectsUsed.put(prebaked.getEffectId(), false); + } + } + + /** Report a call to vibrator method to trigger a vibration as a composition of primitives. */ + void reportComposePrimitives(long halResult, PrimitiveSegment[] primitives) { + mVibratorComposeCount++; + mVibrationCompositionTotalSize += primitives.length; + + if (halResult > 0) { + // If HAL result is positive then it represents the actual duration of the vibration. + // Remove the requested delays to update the total time the vibrator was ON. + for (PrimitiveSegment primitive : primitives) { + halResult -= primitive.getDelay(); + mVibratorPrimitivesUsed.put(primitive.getPrimitiveId(), true); + } + if (halResult > 0) { + mVibratorOnTotalDurationMillis += (int) halResult; + } + } else { + // One or more primitives were unsupported, or request failed. + for (PrimitiveSegment primitive : primitives) { + mVibratorPrimitivesUsed.put(primitive.getPrimitiveId(), false); + } + } + } + + /** Report a call to vibrator method to trigger a vibration as a PWLE. */ + void reportComposePwle(long halResult, RampSegment[] segments) { + mVibratorComposePwleCount++; + mVibrationPwleTotalSize += segments.length; + + if (halResult > 0) { + // If HAL result is positive then it represents the actual duration of the vibration. + // Remove the zero-amplitude segments to update the total time the vibrator was ON. + for (RampSegment ramp : segments) { + if ((ramp.getStartAmplitude() == 0) && (ramp.getEndAmplitude() == 0)) { + halResult -= ramp.getDuration(); + } + } + if (halResult > 0) { + mVibratorOnTotalDurationMillis += (int) halResult; + } + } + } + + /** + * Increment the stats for total number of times the {@code setExternalControl} method was + * triggered in the vibrator HAL. + */ + void reportSetExternalControl() { + mVibratorSetExternalControlCount++; + } + + /** + * Immutable metrics about this vibration, to be kept in memory until it can be pushed through + * {@link com.android.internal.util.FrameworkStatsLog} as a + * {@link com.android.internal.util.FrameworkStatsLog#VIBRATION_REPORTED}. + */ + static final class StatsInfo { + public final int uid; + public final int vibrationType; + public final int usage; + public final int status; + public final boolean endedBySameUid; + public final int endedByUsage; + public final int interruptedUsage; + public final int repeatCount; + public final int totalDurationMillis; + public final int vibratorOnMillis; + public final int startLatencyMillis; + public final int endLatencyMillis; + public final int halComposeCount; + public final int halComposePwleCount; + public final int halOnCount; + public final int halOffCount; + public final int halPerformCount; + public final int halSetAmplitudeCount; + public final int halSetExternalControlCount; + public final int halCompositionSize; + public final int halPwleSize; + public final int[] halSupportedCompositionPrimitivesUsed; + public final int[] halSupportedEffectsUsed; + public final int[] halUnsupportedCompositionPrimitivesUsed; + public final int[] halUnsupportedEffectsUsed; + private boolean mIsWritten; + + StatsInfo(int uid, int vibrationType, int usage, Vibration.Status status, + VibrationStats stats, long completionUptimeMillis) { + this.uid = uid; + this.vibrationType = vibrationType; + this.usage = usage; + this.status = status.getProtoEnumValue(); + endedBySameUid = (uid == stats.mEndedByUid); + endedByUsage = stats.mEndedByUsage; + interruptedUsage = stats.mInterruptedUsage; + repeatCount = stats.mRepeatCount; + + // This duration goes from the time this object was created until the time it was + // completed. We can use latencies to detect the times between first and last + // interaction with vibrator. + totalDurationMillis = + (int) Math.max(0, completionUptimeMillis - stats.mCreateUptimeMillis); + vibratorOnMillis = stats.mVibratorOnTotalDurationMillis; + + if (stats.hasStarted()) { + // We only measure latencies for vibrations that actually triggered the vibrator. + startLatencyMillis = + (int) Math.max(0, stats.mStartUptimeMillis - stats.mCreateUptimeMillis); + endLatencyMillis = + (int) Math.max(0, completionUptimeMillis - stats.mEndUptimeMillis); + } else { + startLatencyMillis = endLatencyMillis = 0; + } + + halComposeCount = stats.mVibratorComposeCount; + halComposePwleCount = stats.mVibratorComposePwleCount; + halOnCount = stats.mVibratorOnCount; + halOffCount = stats.mVibratorOffCount; + halPerformCount = stats.mVibratorPerformCount; + halSetAmplitudeCount = stats.mVibratorSetAmplitudeCount; + halSetExternalControlCount = stats.mVibratorSetExternalControlCount; + halCompositionSize = stats.mVibrationCompositionTotalSize; + halPwleSize = stats.mVibrationPwleTotalSize; + halSupportedCompositionPrimitivesUsed = + filteredKeys(stats.mVibratorPrimitivesUsed, /* supported= */ true); + halSupportedEffectsUsed = + filteredKeys(stats.mVibratorEffectsUsed, /* supported= */ true); + halUnsupportedCompositionPrimitivesUsed = + filteredKeys(stats.mVibratorPrimitivesUsed, /* supported= */ false); + halUnsupportedEffectsUsed = + filteredKeys(stats.mVibratorEffectsUsed, /* supported= */ false); + } + + @VisibleForTesting + boolean isWritten() { + return mIsWritten; + } + + void writeVibrationReported() { + if (mIsWritten) { + Slog.wtf(TAG, "Writing same vibration stats multiple times for uid=" + uid); + } + mIsWritten = true; + // Mapping from this MetricInfo representation and the atom proto VibrationReported. + FrameworkStatsLog.write_non_chained( + FrameworkStatsLog.VIBRATION_REPORTED, + uid, null, vibrationType, usage, status, endedBySameUid, endedByUsage, + interruptedUsage, repeatCount, totalDurationMillis, vibratorOnMillis, + startLatencyMillis, endLatencyMillis, halComposeCount, halComposePwleCount, + halOnCount, halOffCount, halPerformCount, halSetAmplitudeCount, + halSetExternalControlCount, halSupportedCompositionPrimitivesUsed, + halSupportedEffectsUsed, halUnsupportedCompositionPrimitivesUsed, + halUnsupportedEffectsUsed, halCompositionSize, halPwleSize); + } + + private static int[] filteredKeys(SparseBooleanArray supportArray, boolean supported) { + int count = 0; + for (int i = 0; i < supportArray.size(); i++) { + if (supportArray.valueAt(i) == supported) count++; + } + if (count == 0) { + return null; + } + int pos = 0; + int[] res = new int[count]; + for (int i = 0; i < supportArray.size(); i++) { + if (supportArray.valueAt(i) == supported) { + res[pos++] = supportArray.keyAt(i); + } + } + return res; + } + } +} diff --git a/services/core/java/com/android/server/vibrator/VibrationStepConductor.java b/services/core/java/com/android/server/vibrator/VibrationStepConductor.java index e3d806755c6e..0799b955b6f1 100644 --- a/services/core/java/com/android/server/vibrator/VibrationStepConductor.java +++ b/services/core/java/com/android/server/vibrator/VibrationStepConductor.java @@ -81,12 +81,12 @@ final class VibrationStepConductor implements IBinder.DeathRecipient { private final IntArray mSignalVibratorsComplete; @Nullable @GuardedBy("mLock") - private Vibration.Status mSignalCancelStatus = null; + private Vibration.EndInfo mSignalCancel = null; @GuardedBy("mLock") private boolean mSignalCancelImmediate = false; @Nullable - private Vibration.Status mCancelStatus = null; + private Vibration.EndInfo mCancelledVibrationEndInfo = null; private boolean mCancelledImmediately = false; // hard stop private int mPendingVibrateSteps; private int mRemainingStartSequentialEffectSteps; @@ -153,6 +153,9 @@ final class VibrationStepConductor implements IBinder.DeathRecipient { // This count is decremented at the completion of the step, so we don't subtract one. mRemainingStartSequentialEffectSteps = sequentialEffect.getEffects().size(); mNextSteps.offer(new StartSequentialEffectStep(this, sequentialEffect)); + // Vibration will start playing in the Vibrator, following the effect timings and delays. + // Report current time as the vibration start time, for debugging. + mVibration.stats().reportStarted(); } public Vibration getVibration() { @@ -182,24 +185,25 @@ final class VibrationStepConductor implements IBinder.DeathRecipient { * Calculate the {@link Vibration.Status} based on the current queue state and the expected * number of {@link StartSequentialEffectStep} to be played. */ - public Vibration.Status calculateVibrationStatus() { + @Nullable + public Vibration.EndInfo calculateVibrationEndInfo() { if (Build.IS_DEBUGGABLE) { expectIsVibrationThread(true); } - if (mCancelStatus != null) { - return mCancelStatus; + if (mCancelledVibrationEndInfo != null) { + return mCancelledVibrationEndInfo; } - if (mPendingVibrateSteps > 0 - || mRemainingStartSequentialEffectSteps > 0) { - return Vibration.Status.RUNNING; + if (mPendingVibrateSteps > 0 || mRemainingStartSequentialEffectSteps > 0) { + // Vibration still running. + return null; } // No pending steps, and something happened. if (mSuccessfulVibratorOnSteps > 0) { - return Vibration.Status.FINISHED; + return new Vibration.EndInfo(Vibration.Status.FINISHED); } // If no step was able to turn the vibrator ON successfully. - return Vibration.Status.IGNORED_UNSUPPORTED; + return new Vibration.EndInfo(Vibration.Status.IGNORED_UNSUPPORTED); } /** @@ -305,45 +309,50 @@ final class VibrationStepConductor implements IBinder.DeathRecipient { if (DEBUG) { Slog.d(TAG, "Binder died, cancelling vibration..."); } - notifyCancelled(Vibration.Status.CANCELLED_BINDER_DIED, /* immediate= */ false); + notifyCancelled(new Vibration.EndInfo(Vibration.Status.CANCELLED_BINDER_DIED), + /* immediate= */ false); } /** * Notify the execution that cancellation is requested. This will be acted upon * asynchronously in the VibrationThread. * + * <p>Only the first cancel signal will be used to end a cancelled vibration, but subsequent + * calls with {@code immediate} flag set to true can still force the first cancel signal to + * take effect urgently. + * * @param immediate indicates whether cancellation should abort urgently and skip cleanup steps. */ - public void notifyCancelled(@NonNull Vibration.Status cancelStatus, boolean immediate) { + public void notifyCancelled(@NonNull Vibration.EndInfo cancelInfo, boolean immediate) { if (Build.IS_DEBUGGABLE) { expectIsVibrationThread(false); } if (DEBUG) { - Slog.d(TAG, "Vibration cancel requested with status=" + cancelStatus + Slog.d(TAG, "Vibration cancel requested with signal=" + cancelInfo + ", immediate=" + immediate); } - if ((cancelStatus == null) || !cancelStatus.name().startsWith("CANCEL")) { - Slog.w(TAG, "Vibration cancel requested with bad status=" + cancelStatus + if ((cancelInfo == null) || !cancelInfo.status.name().startsWith("CANCEL")) { + Slog.w(TAG, "Vibration cancel requested with bad signal=" + cancelInfo + ", using CANCELLED_UNKNOWN_REASON to ensure cancellation."); - cancelStatus = Vibration.Status.CANCELLED_BY_UNKNOWN_REASON; + cancelInfo = new Vibration.EndInfo(Vibration.Status.CANCELLED_BY_UNKNOWN_REASON); } synchronized (mLock) { - if (immediate && mSignalCancelImmediate || (mSignalCancelStatus != null)) { + if ((immediate && mSignalCancelImmediate) || (mSignalCancel != null)) { if (DEBUG) { Slog.d(TAG, "Vibration cancel request ignored as the vibration " - + mVibration.id + "is already being cancelled with status=" - + mSignalCancelStatus + ", immediate=" + mSignalCancelImmediate); + + mVibration.id + "is already being cancelled with signal=" + + mSignalCancel + ", immediate=" + mSignalCancelImmediate); } return; } mSignalCancelImmediate |= immediate; - if (mSignalCancelStatus == null) { - mSignalCancelStatus = cancelStatus; + if (mSignalCancel == null) { + mSignalCancel = cancelInfo; } else { if (DEBUG) { - Slog.d(TAG, "Vibration cancel request new status=" + cancelStatus - + " ignored as the vibration was already cancelled with status=" - + mSignalCancelStatus + ", but immediate flag was updated to " + Slog.d(TAG, "Vibration cancel request new signal=" + cancelInfo + + " ignored as the vibration was already cancelled with signal=" + + mSignalCancel + ", but immediate flag was updated to " + mSignalCancelImmediate); } } @@ -401,9 +410,9 @@ final class VibrationStepConductor implements IBinder.DeathRecipient { if (Build.IS_DEBUGGABLE) { expectIsVibrationThread(true); // Reads VibrationThread variables as well as signals. } - return (mSignalCancelStatus != mCancelStatus) - || (mSignalCancelImmediate && !mCancelledImmediately) - || (mSignalVibratorsComplete.size() > 0); + return (mSignalCancel != null && mCancelledVibrationEndInfo == null) + || (mSignalCancelImmediate && !mCancelledImmediately) + || (mSignalVibratorsComplete.size() > 0); } /** @@ -416,7 +425,7 @@ final class VibrationStepConductor implements IBinder.DeathRecipient { } int[] vibratorsToProcess = null; - Vibration.Status doCancelStatus = null; + Vibration.EndInfo doCancelInfo = null; boolean doCancelImmediate = false; // Collect signals to process, but don't keep the lock while processing them. synchronized (mLock) { @@ -426,10 +435,10 @@ final class VibrationStepConductor implements IBinder.DeathRecipient { } // This should only happen once. doCancelImmediate = true; - doCancelStatus = mSignalCancelStatus; + doCancelInfo = mSignalCancel; } - if (mSignalCancelStatus != mCancelStatus) { - doCancelStatus = mSignalCancelStatus; + if ((mSignalCancel != null) && (mCancelledVibrationEndInfo == null)) { + doCancelInfo = mSignalCancel; } if (!doCancelImmediate && mSignalVibratorsComplete.size() > 0) { // Swap out the queue of completions to process. @@ -443,11 +452,11 @@ final class VibrationStepConductor implements IBinder.DeathRecipient { // completion signals that were collected in this call, but we won't process them // anyway as all steps are cancelled. if (doCancelImmediate) { - processCancelImmediately(doCancelStatus); + processCancelImmediately(doCancelInfo); return; } - if (doCancelStatus != null) { - processCancel(doCancelStatus); + if (doCancelInfo != null) { + processCancel(doCancelInfo); } if (vibratorsToProcess != null) { processVibratorsComplete(vibratorsToProcess); @@ -460,12 +469,12 @@ final class VibrationStepConductor implements IBinder.DeathRecipient { * <p>This will remove all steps and replace them with respective results of * {@link Step#cancel()}. */ - public void processCancel(Vibration.Status cancelStatus) { + public void processCancel(Vibration.EndInfo cancelInfo) { if (Build.IS_DEBUGGABLE) { expectIsVibrationThread(true); } - mCancelStatus = cancelStatus; + mCancelledVibrationEndInfo = cancelInfo; // Vibrator callbacks should wait until all steps from the queue are properly cancelled // and clean up steps are added back to the queue, so they can handle the callback. List<Step> cleanUpSteps = new ArrayList<>(); @@ -483,13 +492,13 @@ final class VibrationStepConductor implements IBinder.DeathRecipient { * * <p>This will remove and trigger {@link Step#cancelImmediately()} in all steps, in order. */ - public void processCancelImmediately(Vibration.Status cancelStatus) { + public void processCancelImmediately(Vibration.EndInfo cancelInfo) { if (Build.IS_DEBUGGABLE) { expectIsVibrationThread(true); } mCancelledImmediately = true; - mCancelStatus = cancelStatus; + mCancelledVibrationEndInfo = cancelInfo; Step step; while ((step = pollNext()) != null) { step.cancelImmediately(); diff --git a/services/core/java/com/android/server/vibrator/VibrationThread.java b/services/core/java/com/android/server/vibrator/VibrationThread.java index cecc5c04dedc..e824db105abc 100644 --- a/services/core/java/com/android/server/vibrator/VibrationThread.java +++ b/services/core/java/com/android/server/vibrator/VibrationThread.java @@ -76,7 +76,7 @@ final class VibrationThread extends Thread { * cleanup tasks, and should not be given new work until {@link #onVibrationThreadReleased} * is called. */ - void onVibrationCompleted(long vibrationId, Vibration.Status status); + void onVibrationCompleted(long vibrationId, @NonNull Vibration.EndInfo vibrationEndInfo); /** * Tells the manager that the VibrationThread is finished with the previous vibration and @@ -237,7 +237,8 @@ final class VibrationThread extends Thread { try { runCurrentVibrationWithWakeLockAndDeathLink(); } finally { - clientVibrationCompleteIfNotAlready(Vibration.Status.FINISHED_UNEXPECTED); + clientVibrationCompleteIfNotAlready( + new Vibration.EndInfo(Vibration.Status.FINISHED_UNEXPECTED)); } } finally { mWakeLock.release(); @@ -255,7 +256,8 @@ final class VibrationThread extends Thread { vibrationBinderToken.linkToDeath(mExecutingConductor, 0); } catch (RemoteException e) { Slog.e(TAG, "Error linking vibration to token death", e); - clientVibrationCompleteIfNotAlready(Vibration.Status.IGNORED_ERROR_TOKEN); + clientVibrationCompleteIfNotAlready( + new Vibration.EndInfo(Vibration.Status.IGNORED_ERROR_TOKEN)); return; } // Ensure that the unlink always occurs now. @@ -274,11 +276,11 @@ final class VibrationThread extends Thread { // Indicate that the vibration is complete. This can be called multiple times only for // convenience of handling error conditions - an error after the client is complete won't // affect the status. - private void clientVibrationCompleteIfNotAlready(Vibration.Status completedStatus) { + private void clientVibrationCompleteIfNotAlready(@NonNull Vibration.EndInfo vibrationEndInfo) { if (!mCalledVibrationCompleteCallback) { mCalledVibrationCompleteCallback = true; mVibratorManagerHooks.onVibrationCompleted( - mExecutingConductor.getVibration().id, completedStatus); + mExecutingConductor.getVibration().id, vibrationEndInfo); } } @@ -298,12 +300,15 @@ final class VibrationThread extends Thread { mExecutingConductor.runNextStep(); } - Vibration.Status status = mExecutingConductor.calculateVibrationStatus(); - // This block can only run once due to mCalledVibrationCompleteCallback. - if (status != Vibration.Status.RUNNING && !mCalledVibrationCompleteCallback) { - // First time vibration stopped running, start clean-up tasks and notify - // callback immediately. - clientVibrationCompleteIfNotAlready(status); + if (!mCalledVibrationCompleteCallback) { + // This block can only run once due to mCalledVibrationCompleteCallback. + Vibration.EndInfo vibrationEndInfo = + mExecutingConductor.calculateVibrationEndInfo(); + if (vibrationEndInfo != null) { + // First time vibration stopped running, start clean-up tasks and notify + // callback immediately. + clientVibrationCompleteIfNotAlready(vibrationEndInfo); + } } } } finally { diff --git a/services/core/java/com/android/server/vibrator/VibratorFrameworkStatsLogger.java b/services/core/java/com/android/server/vibrator/VibratorFrameworkStatsLogger.java new file mode 100644 index 000000000000..f600a2964cbc --- /dev/null +++ b/services/core/java/com/android/server/vibrator/VibratorFrameworkStatsLogger.java @@ -0,0 +1,140 @@ +/* + * Copyright (C) 2022 The Android Open Source Project + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +package com.android.server.vibrator; + +import android.os.Handler; +import android.os.SystemClock; +import android.util.Slog; + +import com.android.internal.annotations.GuardedBy; +import com.android.internal.annotations.VisibleForTesting; +import com.android.internal.util.FrameworkStatsLog; + +import java.util.ArrayDeque; +import java.util.Queue; + +/** Helper class for async write of atoms to {@link FrameworkStatsLog} using a given Handler. */ +public class VibratorFrameworkStatsLogger { + private static final String TAG = "VibratorFrameworkStatsLogger"; + + // VibrationReported pushed atom needs to be throttled to at most one every 10ms. + private static final int VIBRATION_REPORTED_MIN_INTERVAL_MILLIS = 10; + // We accumulate events that should take 3s to write and drop excessive metrics. + private static final int VIBRATION_REPORTED_MAX_QUEUE_SIZE = 300; + // Warning about dropping entries after this amount of atoms were dropped by the throttle. + private static final int VIBRATION_REPORTED_WARNING_QUEUE_SIZE = 200; + + private final Object mLock = new Object(); + private final Handler mHandler; + private final long mVibrationReportedLogIntervalMillis; + private final long mVibrationReportedQueueMaxSize; + private final Runnable mConsumeVibrationStatsQueueRunnable = + () -> writeVibrationReportedFromQueue(); + + @GuardedBy("mLock") + private long mLastVibrationReportedLogUptime; + @GuardedBy("mLock") + private Queue<VibrationStats.StatsInfo> mVibrationStatsQueue = new ArrayDeque<>(); + + VibratorFrameworkStatsLogger(Handler handler) { + this(handler, VIBRATION_REPORTED_MIN_INTERVAL_MILLIS, VIBRATION_REPORTED_MAX_QUEUE_SIZE); + } + + @VisibleForTesting + VibratorFrameworkStatsLogger(Handler handler, int vibrationReportedLogIntervalMillis, + int vibrationReportedQueueMaxSize) { + mHandler = handler; + mVibrationReportedLogIntervalMillis = vibrationReportedLogIntervalMillis; + mVibrationReportedQueueMaxSize = vibrationReportedQueueMaxSize; + } + + /** Writes {@link FrameworkStatsLog#VIBRATOR_STATE_CHANGED} for state ON. */ + public void writeVibratorStateOnAsync(int uid, long duration) { + mHandler.post( + () -> FrameworkStatsLog.write_non_chained( + FrameworkStatsLog.VIBRATOR_STATE_CHANGED, uid, null, + FrameworkStatsLog.VIBRATOR_STATE_CHANGED__STATE__ON, duration)); + } + + /** Writes {@link FrameworkStatsLog#VIBRATOR_STATE_CHANGED} for state OFF. */ + public void writeVibratorStateOffAsync(int uid) { + mHandler.post( + () -> FrameworkStatsLog.write_non_chained( + FrameworkStatsLog.VIBRATOR_STATE_CHANGED, uid, null, + FrameworkStatsLog.VIBRATOR_STATE_CHANGED__STATE__OFF, + /* duration= */ 0)); + } + + /** + * Writes {@link FrameworkStatsLog#VIBRATION_REPORTED} for given vibration. + * + * <p>This atom is throttled to be pushed once every 10ms, so this logger can keep a queue of + * {@link VibrationStats.StatsInfo} entries to slowly write to statsd. + */ + public void writeVibrationReportedAsync(VibrationStats.StatsInfo metrics) { + boolean needsScheduling; + long scheduleDelayMs; + int queueSize; + + synchronized (mLock) { + queueSize = mVibrationStatsQueue.size(); + needsScheduling = (queueSize == 0); + + if (queueSize < mVibrationReportedQueueMaxSize) { + mVibrationStatsQueue.offer(metrics); + } + + long nextLogUptime = + mLastVibrationReportedLogUptime + mVibrationReportedLogIntervalMillis; + scheduleDelayMs = Math.max(0, nextLogUptime - SystemClock.uptimeMillis()); + } + + if ((queueSize + 1) == VIBRATION_REPORTED_WARNING_QUEUE_SIZE) { + Slog.w(TAG, " Approaching vibration metrics queue limit, events might be dropped."); + } + + if (needsScheduling) { + mHandler.postDelayed(mConsumeVibrationStatsQueueRunnable, scheduleDelayMs); + } + } + + /** Writes next {@link FrameworkStatsLog#VIBRATION_REPORTED} from the queue. */ + private void writeVibrationReportedFromQueue() { + boolean needsScheduling; + VibrationStats.StatsInfo stats; + + synchronized (mLock) { + stats = mVibrationStatsQueue.poll(); + needsScheduling = !mVibrationStatsQueue.isEmpty(); + + if (stats != null) { + mLastVibrationReportedLogUptime = SystemClock.uptimeMillis(); + } + } + + if (stats == null) { + Slog.w(TAG, "Unexpected vibration metric flush with empty queue. Ignoring."); + } else { + stats.writeVibrationReported(); + } + + if (needsScheduling) { + mHandler.postDelayed(mConsumeVibrationStatsQueueRunnable, + mVibrationReportedLogIntervalMillis); + } + } +} diff --git a/services/core/java/com/android/server/vibrator/VibratorManagerService.java b/services/core/java/com/android/server/vibrator/VibratorManagerService.java index 5ac2f4f27452..2f12a820eb81 100644 --- a/services/core/java/com/android/server/vibrator/VibratorManagerService.java +++ b/services/core/java/com/android/server/vibrator/VibratorManagerService.java @@ -129,6 +129,7 @@ public class VibratorManagerService extends IVibratorManagerService.Stub { private final Context mContext; private final PowerManager.WakeLock mWakeLock; private final IBatteryStats mBatteryStatsService; + private final VibratorFrameworkStatsLogger mFrameworkStatsLogger; private final Handler mHandler; private final VibrationThread mVibrationThread; private final AppOpsManager mAppOps; @@ -163,10 +164,12 @@ public class VibratorManagerService extends IVibratorManagerService.Stub { // When the system is entering a non-interactive state, we want to cancel // vibrations in case a misbehaving app has abandoned them. if (shouldCancelOnScreenOffLocked(mNextVibration)) { - clearNextVibrationLocked(Vibration.Status.CANCELLED_BY_SCREEN_OFF); + clearNextVibrationLocked( + new Vibration.EndInfo(Vibration.Status.CANCELLED_BY_SCREEN_OFF)); } if (shouldCancelOnScreenOffLocked(mCurrentVibration)) { - mCurrentVibration.notifyCancelled(Vibration.Status.CANCELLED_BY_SCREEN_OFF, + mCurrentVibration.notifyCancelled( + new Vibration.EndInfo(Vibration.Status.CANCELLED_BY_SCREEN_OFF), /* immediate= */ false); } } @@ -207,6 +210,7 @@ public class VibratorManagerService extends IVibratorManagerService.Stub { mVibratorManagerRecords = new VibratorManagerRecords(dumpLimit); mBatteryStatsService = injector.getBatteryStatsService(); + mFrameworkStatsLogger = injector.getFrameworkStatsLogger(mHandler); mAppOps = mContext.getSystemService(AppOpsManager.class); @@ -384,7 +388,8 @@ public class VibratorManagerService extends IVibratorManagerService.Stub { * The Vibration is only returned if it is ongoing after this method returns. */ @Nullable - private Vibration vibrateInternal(int uid, String opPkg, @NonNull CombinedVibration effect, + @VisibleForTesting + Vibration vibrateInternal(int uid, String opPkg, @NonNull CombinedVibration effect, @Nullable VibrationAttributes attrs, String reason, IBinder token) { Trace.traceBegin(Trace.TRACE_TAG_VIBRATOR, "vibrate, reason = " + reason); try { @@ -399,6 +404,7 @@ public class VibratorManagerService extends IVibratorManagerService.Stub { return null; } attrs = fixupVibrationAttributes(attrs, effect); + // Create Vibration.Stats as close to the received request as possible, for tracking. Vibration vib = new Vibration(token, mNextVibrationId.getAndIncrement(), effect, attrs, uid, opPkg, reason); fillVibrationFallbacks(vib, effect); @@ -413,32 +419,56 @@ public class VibratorManagerService extends IVibratorManagerService.Stub { if (DEBUG) { Slog.d(TAG, "Starting vibrate for vibration " + vib.id); } - Vibration.Status ignoreStatus = shouldIgnoreVibrationLocked( - vib.uid, vib.opPkg, vib.attrs); - - if (ignoreStatus == null) { - ignoreStatus = shouldIgnoreVibrationForOngoingLocked(vib); + int ignoredByUid = -1; + int ignoredByUsage = -1; + Vibration.Status status = null; + + // Check if user settings or DnD is set to ignore this vibration. + status = shouldIgnoreVibrationLocked(vib.uid, vib.opPkg, vib.attrs); + + // Check if something has external control, assume it's more important. + if ((status == null) && (mCurrentExternalVibration != null)) { + status = Vibration.Status.IGNORED_FOR_EXTERNAL; + ignoredByUid = mCurrentExternalVibration.externalVibration.getUid(); + ignoredByUsage = mCurrentExternalVibration.externalVibration + .getVibrationAttributes().getUsage(); } - if (ignoreStatus != null) { - endVibrationLocked(vib, ignoreStatus); - return vib; + // Check if ongoing vibration is more important than this vibration. + if (status == null) { + status = shouldIgnoreVibrationForOngoingLocked(vib); + if (status != null) { + ignoredByUid = mCurrentVibration.getVibration().uid; + ignoredByUsage = mCurrentVibration.getVibration().attrs.getUsage(); + } } - final long ident = Binder.clearCallingIdentity(); - try { - if (mCurrentVibration != null) { - mCurrentVibration.notifyCancelled(Vibration.Status.CANCELLED_SUPERSEDED, - /* immediate= */ false); - } - Vibration.Status status = startVibrationLocked(vib); - if (status != Vibration.Status.RUNNING) { - endVibrationLocked(vib, status); + // If not ignored so far then try to start this vibration. + if (status == null) { + final long ident = Binder.clearCallingIdentity(); + try { + if (mCurrentVibration != null) { + vib.stats().reportInterruptedAnotherVibration( + mCurrentVibration.getVibration().attrs.getUsage()); + mCurrentVibration.notifyCancelled( + new Vibration.EndInfo( + Vibration.Status.CANCELLED_SUPERSEDED, vib.uid, + vib.attrs.getUsage()), + /* immediate= */ false); + } + status = startVibrationLocked(vib); + } finally { + Binder.restoreCallingIdentity(ident); } - return vib; - } finally { - Binder.restoreCallingIdentity(ident); } + + // Ignored or failed to start the vibration, end it and report metrics right away. + if (status != Vibration.Status.RUNNING) { + endVibrationLocked(vib, + new Vibration.EndInfo(status, ignoredByUid, ignoredByUsage), + /* shouldWriteStats= */ true); + } + return vib; } } finally { Trace.traceEnd(Trace.TRACE_TAG_VIBRATOR); @@ -457,26 +487,28 @@ public class VibratorManagerService extends IVibratorManagerService.Stub { if (DEBUG) { Slog.d(TAG, "Canceling vibration"); } + Vibration.EndInfo cancelledByUserInfo = + new Vibration.EndInfo(Vibration.Status.CANCELLED_BY_USER); final long ident = Binder.clearCallingIdentity(); try { if (mNextVibration != null && shouldCancelVibration(mNextVibration.getVibration(), usageFilter, token)) { - clearNextVibrationLocked(Vibration.Status.CANCELLED_BY_USER); + clearNextVibrationLocked(cancelledByUserInfo); } if (mCurrentVibration != null && shouldCancelVibration(mCurrentVibration.getVibration(), usageFilter, token)) { - mCurrentVibration.notifyCancelled(Vibration.Status.CANCELLED_BY_USER, - /* immediate= */false); + mCurrentVibration.notifyCancelled( + cancelledByUserInfo, /* immediate= */false); } if (mCurrentExternalVibration != null && shouldCancelVibration( mCurrentExternalVibration.externalVibration.getVibrationAttributes(), usageFilter)) { - mCurrentExternalVibration.externalVibration.mute(); - endExternalVibrateLocked(Vibration.Status.CANCELLED_BY_USER, - /* continueExternalControl= */ false); + mCurrentExternalVibration.mute(); + endExternalVibrateLocked( + cancelledByUserInfo, /* continueExternalControl= */ false); } } finally { Binder.restoreCallingIdentity(ident); @@ -604,15 +636,17 @@ public class VibratorManagerService extends IVibratorManagerService.Stub { Slog.d(TAG, "Canceling vibration because settings changed: " + (inputDevicesChanged ? "input devices changed" : ignoreStatus)); } - mCurrentVibration.notifyCancelled(Vibration.Status.CANCELLED_BY_SETTINGS_UPDATE, + mCurrentVibration.notifyCancelled( + new Vibration.EndInfo(Vibration.Status.CANCELLED_BY_SETTINGS_UPDATE), /* immediate= */ false); } } } - private void setExternalControl(boolean externalControl) { + private void setExternalControl(boolean externalControl, VibrationStats vibrationStats) { for (int i = 0; i < mVibrators.size(); i++) { mVibrators.valueAt(i).setExternalControl(externalControl); + vibrationStats.reportSetExternalControl(); } } @@ -654,7 +688,9 @@ public class VibratorManagerService extends IVibratorManagerService.Stub { } // If there's already a vibration queued (waiting for the previous one to finish // cancelling), end it cleanly and replace it with the new one. - clearNextVibrationLocked(Vibration.Status.IGNORED_SUPERSEDED); + clearNextVibrationLocked( + new Vibration.EndInfo(Vibration.Status.IGNORED_SUPERSEDED, + vib.uid, vib.attrs.getUsage())); mNextVibration = conductor; return Vibration.Status.RUNNING; } finally { @@ -671,6 +707,7 @@ public class VibratorManagerService extends IVibratorManagerService.Stub { switch (mode) { case AppOpsManager.MODE_ALLOWED: Trace.asyncTraceBegin(Trace.TRACE_TAG_VIBRATOR, "vibration", 0); + // Make sure mCurrentVibration is set while triggering the VibrationThread. mCurrentVibration = conductor; if (!mVibrationThread.runVibrationOnVibrationThread(mCurrentVibration)) { // Shouldn't happen. The method call already logs a wtf. @@ -690,18 +727,26 @@ public class VibratorManagerService extends IVibratorManagerService.Stub { } @GuardedBy("mLock") - private void endVibrationLocked(Vibration vib, Vibration.Status status) { - vib.end(status); - logVibrationStatus(vib.uid, vib.attrs, status); + private void endVibrationLocked(Vibration vib, Vibration.EndInfo vibrationEndInfo, + boolean shouldWriteStats) { + vib.end(vibrationEndInfo); + logVibrationStatus(vib.uid, vib.attrs, vibrationEndInfo.status); mVibratorManagerRecords.record(vib); + if (shouldWriteStats) { + mFrameworkStatsLogger.writeVibrationReportedAsync( + vib.getStatsInfo(/* completionUptimeMillis= */ SystemClock.uptimeMillis())); + } } @GuardedBy("mLock") - private void endVibrationLocked(ExternalVibrationHolder vib, Vibration.Status status) { - vib.end(status); + private void endVibrationAndWriteStatsLocked(ExternalVibrationHolder vib, + Vibration.EndInfo vibrationEndInfo) { + vib.end(vibrationEndInfo); logVibrationStatus(vib.externalVibration.getUid(), - vib.externalVibration.getVibrationAttributes(), status); + vib.externalVibration.getVibrationAttributes(), vibrationEndInfo.status); mVibratorManagerRecords.record(vib); + mFrameworkStatsLogger.writeVibrationReportedAsync( + vib.getStatsInfo(/* completionUptimeMillis= */ SystemClock.uptimeMillis())); } private void logVibrationStatus(int uid, VibrationAttributes attrs, Vibration.Status status) { @@ -744,15 +789,17 @@ public class VibratorManagerService extends IVibratorManagerService.Stub { } @GuardedBy("mLock") - private void reportFinishedVibrationLocked(Vibration.Status status) { + private void reportFinishedVibrationLocked(Vibration.EndInfo vibrationEndInfo) { Trace.traceBegin(Trace.TRACE_TAG_VIBRATOR, "reportFinishVibrationLocked"); Trace.asyncTraceEnd(Trace.TRACE_TAG_VIBRATOR, "vibration", 0); try { Vibration vib = mCurrentVibration.getVibration(); if (DEBUG) { - Slog.d(TAG, "Reporting vibration " + vib.id + " finished with status " + status); + Slog.d(TAG, "Reporting vibration " + vib.id + " finished with " + vibrationEndInfo); } - endVibrationLocked(vib, status); + // DO NOT write metrics at this point, wait for the VibrationThread to report the + // vibration was released, after all cleanup. The metrics will be reported then. + endVibrationLocked(vib, vibrationEndInfo, /* shouldWriteStats= */ false); finishAppOpModeLocked(vib.uid, vib.opPkg); } finally { Trace.traceEnd(Trace.TRACE_TAG_VIBRATOR); @@ -791,11 +838,6 @@ public class VibratorManagerService extends IVibratorManagerService.Stub { @GuardedBy("mLock") @Nullable private Vibration.Status shouldIgnoreVibrationForOngoingLocked(Vibration vib) { - if (mCurrentExternalVibration != null) { - // If something has external control of the vibrator, assume that it's more important. - return Vibration.Status.IGNORED_FOR_EXTERNAL; - } - if (mCurrentVibration == null || vib.isRepeating()) { // Incoming repeating vibrations always take precedence over ongoing vibrations. return null; @@ -1122,7 +1164,7 @@ public class VibratorManagerService extends IVibratorManagerService.Stub { } Vibration vib = conductor.getVibration(); return mVibrationSettings.shouldCancelVibrationOnScreenOff( - vib.uid, vib.opPkg, vib.attrs.getUsage(), vib.startUptimeMillis); + vib.uid, vib.opPkg, vib.attrs.getUsage(), vib.stats().getCreateUptimeMillis()); } @GuardedBy("mLock") @@ -1158,6 +1200,10 @@ public class VibratorManagerService extends IVibratorManagerService.Stub { BatteryStats.SERVICE_NAME)); } + VibratorFrameworkStatsLogger getFrameworkStatsLogger(Handler handler) { + return new VibratorFrameworkStatsLogger(handler); + } + VibratorController createVibratorController(int vibratorId, VibratorController.OnVibrationCompleteListener listener) { return new VibratorController(vibratorId, listener); @@ -1197,6 +1243,10 @@ public class VibratorManagerService extends IVibratorManagerService.Stub { public void noteVibratorOn(int uid, long duration) { try { if (duration <= 0) { + // Tried to turn vibrator ON and got: + // duration == 0: Unsupported effect/method or zero-amplitude segment. + // duration < 0: Unexpected error triggering the vibrator. + // Skip battery stats and atom metric for VibratorStageChanged to ON. return; } if (duration == Long.MAX_VALUE) { @@ -1205,10 +1255,9 @@ public class VibratorManagerService extends IVibratorManagerService.Stub { duration = BATTERY_STATS_REPEATING_VIBRATION_DURATION; } mBatteryStatsService.noteVibratorOn(uid, duration); - FrameworkStatsLog.write_non_chained(FrameworkStatsLog.VIBRATOR_STATE_CHANGED, - uid, null, FrameworkStatsLog.VIBRATOR_STATE_CHANGED__STATE__ON, - duration); + mFrameworkStatsLogger.writeVibratorStateOnAsync(uid, duration); } catch (RemoteException e) { + Slog.e(TAG, "Error logging VibratorStateChanged to ON", e); } } @@ -1216,22 +1265,21 @@ public class VibratorManagerService extends IVibratorManagerService.Stub { public void noteVibratorOff(int uid) { try { mBatteryStatsService.noteVibratorOff(uid); - FrameworkStatsLog.write_non_chained(FrameworkStatsLog.VIBRATOR_STATE_CHANGED, - uid, null, FrameworkStatsLog.VIBRATOR_STATE_CHANGED__STATE__OFF, - /* duration= */ 0); + mFrameworkStatsLogger.writeVibratorStateOffAsync(uid); } catch (RemoteException e) { + Slog.e(TAG, "Error logging VibratorStateChanged to OFF", e); } } @Override - public void onVibrationCompleted(long vibrationId, Vibration.Status status) { + public void onVibrationCompleted(long vibrationId, Vibration.EndInfo vibrationEndInfo) { if (DEBUG) { - Slog.d(TAG, "Vibration " + vibrationId + " finished with status " + status); + Slog.d(TAG, "Vibration " + vibrationId + " finished with " + vibrationEndInfo); } synchronized (mLock) { if (mCurrentVibration != null && mCurrentVibration.getVibration().id == vibrationId) { - reportFinishedVibrationLocked(status); + reportFinishedVibrationLocked(vibrationEndInfo); } } } @@ -1251,13 +1299,21 @@ public class VibratorManagerService extends IVibratorManagerService.Stub { "VibrationId mismatch on release. expected=%d, released=%d", mCurrentVibration.getVibration().id, vibrationId)); } - mCurrentVibration = null; + if (mCurrentVibration != null) { + // This is when we consider the current vibration complete, so report metrics. + mFrameworkStatsLogger.writeVibrationReportedAsync( + mCurrentVibration.getVibration().getStatsInfo( + /* completionUptimeMillis= */ SystemClock.uptimeMillis())); + mCurrentVibration = null; + } if (mNextVibration != null) { VibrationStepConductor nextConductor = mNextVibration; mNextVibration = null; Vibration.Status status = startVibrationOnThreadLocked(nextConductor); if (status != Vibration.Status.RUNNING) { - endVibrationLocked(nextConductor.getVibration(), status); + // Failed to start the vibration, end it and report metrics right away. + endVibrationLocked(nextConductor.getVibration(), + new Vibration.EndInfo(status), /* shouldWriteStats= */ true); } } } @@ -1325,31 +1381,48 @@ public class VibratorManagerService extends IVibratorManagerService.Stub { private final class ExternalVibrationHolder implements IBinder.DeathRecipient { public final ExternalVibration externalVibration; + public final VibrationStats stats = new VibrationStats(); public int scale; - private final long mStartUptimeMillis; - private final long mStartTimeDebug; - - private long mEndUptimeMillis; - private long mEndTimeDebug; private Vibration.Status mStatus; private ExternalVibrationHolder(ExternalVibration externalVibration) { this.externalVibration = externalVibration; this.scale = IExternalVibratorService.SCALE_NONE; - mStartUptimeMillis = SystemClock.uptimeMillis(); - mStartTimeDebug = System.currentTimeMillis(); mStatus = Vibration.Status.RUNNING; } - public void end(Vibration.Status status) { + public void mute() { + externalVibration.mute(); + } + + public void linkToDeath() { + externalVibration.linkToDeath(this); + } + + public void unlinkToDeath() { + externalVibration.unlinkToDeath(this); + } + + public boolean isHoldingSameVibration(ExternalVibration externalVibration) { + return this.externalVibration.equals(externalVibration); + } + + public void end(Vibration.EndInfo info) { if (mStatus != Vibration.Status.RUNNING) { - // Vibration already ended, keep first ending status set and ignore this one. + // Already ended, ignore this call return; } - mStatus = status; - mEndUptimeMillis = SystemClock.uptimeMillis(); - mEndTimeDebug = System.currentTimeMillis(); + mStatus = info.status; + stats.reportEnded(info.endedByUid, info.endedByUsage); + + if (stats.hasStarted()) { + // External vibration doesn't have feedback from total time the vibrator was playing + // with non-zero amplitude, so we use the duration between start and end times of + // the vibration as the time the vibrator was ON, since the haptic channels are + // open for this duration and can receive vibration waveform data. + stats.reportVibratorOn(stats.getEndUptimeMillis() - stats.getStartUptimeMillis()); + } } public void binderDied() { @@ -1358,19 +1431,26 @@ public class VibratorManagerService extends IVibratorManagerService.Stub { if (DEBUG) { Slog.d(TAG, "External vibration finished because binder died"); } - endExternalVibrateLocked(Vibration.Status.CANCELLED_BINDER_DIED, + endExternalVibrateLocked( + new Vibration.EndInfo(Vibration.Status.CANCELLED_BINDER_DIED), /* continueExternalControl= */ false); } } } public Vibration.DebugInfo getDebugInfo() { - long durationMs = mEndUptimeMillis == 0 ? -1 : mEndUptimeMillis - mStartUptimeMillis; return new Vibration.DebugInfo( - mStartTimeDebug, mEndTimeDebug, durationMs, - /* effect= */ null, /* originalEffect= */ null, scale, + mStatus, stats, /* effect= */ null, /* originalEffect= */ null, scale, externalVibration.getVibrationAttributes(), externalVibration.getUid(), - externalVibration.getPackage(), /* reason= */ null, mStatus); + externalVibration.getPackage(), /* reason= */ null); + } + + public VibrationStats.StatsInfo getStatsInfo(long completionUptimeMillis) { + return new VibrationStats.StatsInfo( + externalVibration.getUid(), + FrameworkStatsLog.VIBRATION_REPORTED__VIBRATION_TYPE__EXTERNAL, + externalVibration.getVibrationAttributes().getUsage(), mStatus, stats, + completionUptimeMillis); } } @@ -1500,9 +1580,11 @@ public class VibratorManagerService extends IVibratorManagerService.Stub { /** Clears mNextVibration if set, ending it cleanly */ @GuardedBy("mLock") - private void clearNextVibrationLocked(Vibration.Status endStatus) { + private void clearNextVibrationLocked(Vibration.EndInfo vibrationEndInfo) { if (mNextVibration != null) { - endVibrationLocked(mNextVibration.getVibration(), endStatus); + // Clearing next vibration before playing it, end it and report metrics right away. + endVibrationLocked(mNextVibration.getVibration(), vibrationEndInfo, + /* shouldWriteStats= */ true); mNextVibration = null; } } @@ -1510,25 +1592,25 @@ public class VibratorManagerService extends IVibratorManagerService.Stub { /** * Ends the external vibration, and clears related service state. * - * @param status the status to end the associated Vibration with + * @param vibrationEndInfo the status and related info to end the associated Vibration with * @param continueExternalControl indicates whether external control will continue. If not, the * HAL will have external control turned off. */ @GuardedBy("mLock") - private void endExternalVibrateLocked(Vibration.Status status, + private void endExternalVibrateLocked(Vibration.EndInfo vibrationEndInfo, boolean continueExternalControl) { Trace.traceBegin(Trace.TRACE_TAG_VIBRATOR, "endExternalVibrateLocked"); try { if (mCurrentExternalVibration == null) { return; } - endVibrationLocked(mCurrentExternalVibration, status); - mCurrentExternalVibration.externalVibration.unlinkToDeath( - mCurrentExternalVibration); - mCurrentExternalVibration = null; + mCurrentExternalVibration.unlinkToDeath(); if (!continueExternalControl) { - setExternalControl(false); + setExternalControl(false, mCurrentExternalVibration.stats); } + // The external control was turned off, end it and report metrics right away. + endVibrationAndWriteStatsLocked(mCurrentExternalVibration, vibrationEndInfo); + mCurrentExternalVibration = null; } finally { Trace.traceEnd(Trace.TRACE_TAG_VIBRATOR); } @@ -1552,6 +1634,8 @@ public class VibratorManagerService extends IVibratorManagerService.Stub { return IExternalVibratorService.SCALE_MUTE; } + // Create Vibration.Stats as close to the received request as possible, for tracking. + ExternalVibrationHolder vibHolder = new ExternalVibrationHolder(vib); VibrationAttributes attrs = fixupVibrationAttributes(vib.getVibrationAttributes(), /* effect= */ null); if (attrs.isFlagSet(VibrationAttributes.FLAG_INVALIDATE_SETTINGS_CACHE)) { @@ -1562,18 +1646,17 @@ public class VibratorManagerService extends IVibratorManagerService.Stub { boolean alreadyUnderExternalControl = false; boolean waitForCompletion = false; - int scale; synchronized (mLock) { Vibration.Status ignoreStatus = shouldIgnoreVibrationLocked( vib.getUid(), vib.getPackage(), attrs); if (ignoreStatus != null) { - ExternalVibrationHolder vibHolder = new ExternalVibrationHolder(vib); vibHolder.scale = IExternalVibratorService.SCALE_MUTE; - endVibrationLocked(vibHolder, ignoreStatus); + // Failed to start the vibration, end it and report metrics right away. + endVibrationAndWriteStatsLocked(vibHolder, new Vibration.EndInfo(ignoreStatus)); return vibHolder.scale; } if (mCurrentExternalVibration != null - && mCurrentExternalVibration.externalVibration.equals(vib)) { + && mCurrentExternalVibration.isHoldingSameVibration(vib)) { // We are already playing this external vibration, so we can return the same // scale calculated in the previous call to this method. return mCurrentExternalVibration.scale; @@ -1582,8 +1665,14 @@ public class VibratorManagerService extends IVibratorManagerService.Stub { // If we're not under external control right now, then cancel any normal // vibration that may be playing and ready the vibrator for external control. if (mCurrentVibration != null) { - clearNextVibrationLocked(Vibration.Status.IGNORED_FOR_EXTERNAL); - mCurrentVibration.notifyCancelled(Vibration.Status.CANCELLED_SUPERSEDED, + vibHolder.stats.reportInterruptedAnotherVibration( + mCurrentVibration.getVibration().attrs.getUsage()); + clearNextVibrationLocked( + new Vibration.EndInfo(Vibration.Status.IGNORED_FOR_EXTERNAL, + vib.getUid(), attrs.getUsage())); + mCurrentVibration.notifyCancelled( + new Vibration.EndInfo(Vibration.Status.CANCELLED_SUPERSEDED, + vib.getUid(), attrs.getUsage()), /* immediate= */ true); waitForCompletion = true; } @@ -1597,22 +1686,27 @@ public class VibratorManagerService extends IVibratorManagerService.Stub { // Note that this doesn't support multiple concurrent external controls, as we // would need to mute the old one still if it came from a different controller. alreadyUnderExternalControl = true; - mCurrentExternalVibration.externalVibration.mute(); - endExternalVibrateLocked(Vibration.Status.CANCELLED_SUPERSEDED, + mCurrentExternalVibration.mute(); + vibHolder.stats.reportInterruptedAnotherVibration( + mCurrentExternalVibration.externalVibration + .getVibrationAttributes().getUsage()); + endExternalVibrateLocked( + new Vibration.EndInfo(Vibration.Status.CANCELLED_SUPERSEDED, + vib.getUid(), attrs.getUsage()), /* continueExternalControl= */ true); } - mCurrentExternalVibration = new ExternalVibrationHolder(vib); - vib.linkToDeath(mCurrentExternalVibration); - mCurrentExternalVibration.scale = mVibrationScaler.getExternalVibrationScale( - attrs.getUsage()); - scale = mCurrentExternalVibration.scale; + mCurrentExternalVibration = vibHolder; + vibHolder.linkToDeath(); + vibHolder.scale = mVibrationScaler.getExternalVibrationScale(attrs.getUsage()); } if (waitForCompletion) { if (!mVibrationThread.waitForThreadIdle(VIBRATION_CANCEL_WAIT_MILLIS)) { Slog.e(TAG, "Timed out waiting for vibration to cancel"); synchronized (mLock) { - endExternalVibrateLocked(Vibration.Status.IGNORED_ERROR_CANCELLING, + // Trigger endExternalVibrateLocked to unlink to death recipient. + endExternalVibrateLocked( + new Vibration.EndInfo(Vibration.Status.IGNORED_ERROR_CANCELLING), /* continueExternalControl= */ false); } return IExternalVibratorService.SCALE_MUTE; @@ -1622,23 +1716,27 @@ public class VibratorManagerService extends IVibratorManagerService.Stub { if (DEBUG) { Slog.d(TAG, "Vibrator going under external control."); } - setExternalControl(true); + setExternalControl(true, vibHolder.stats); } if (DEBUG) { Slog.e(TAG, "Playing external vibration: " + vib); } - return scale; + // Vibrator will start receiving data from external channels after this point. + // Report current time as the vibration start time, for debugging. + vibHolder.stats.reportStarted(); + return vibHolder.scale; } @Override public void onExternalVibrationStop(ExternalVibration vib) { synchronized (mLock) { if (mCurrentExternalVibration != null - && mCurrentExternalVibration.externalVibration.equals(vib)) { + && mCurrentExternalVibration.isHoldingSameVibration(vib)) { if (DEBUG) { Slog.e(TAG, "Stopping external vibration" + vib); } - endExternalVibrateLocked(Vibration.Status.FINISHED, + endExternalVibrateLocked( + new Vibration.EndInfo(Vibration.Status.FINISHED), /* continueExternalControl= */ false); } } diff --git a/services/tests/servicestests/src/com/android/server/vibrator/FakeVibratorControllerProvider.java b/services/tests/servicestests/src/com/android/server/vibrator/FakeVibratorControllerProvider.java index fa3fcd9e9475..235849c1cd8b 100644 --- a/services/tests/servicestests/src/com/android/server/vibrator/FakeVibratorControllerProvider.java +++ b/services/tests/servicestests/src/com/android/server/vibrator/FakeVibratorControllerProvider.java @@ -127,9 +127,17 @@ final class FakeVibratorControllerProvider { } @Override - public long compose(PrimitiveSegment[] effects, long vibrationId) { + public long compose(PrimitiveSegment[] primitives, long vibrationId) { + if (mSupportedPrimitives == null) { + return 0; + } + for (PrimitiveSegment primitive : primitives) { + if (Arrays.binarySearch(mSupportedPrimitives, primitive.getPrimitiveId()) < 0) { + return 0; + } + } long duration = 0; - for (PrimitiveSegment primitive : effects) { + for (PrimitiveSegment primitive : primitives) { duration += EFFECT_DURATION + primitive.getDelay(); recordEffectSegment(vibrationId, primitive); } diff --git a/services/tests/servicestests/src/com/android/server/vibrator/VibrationTest.java b/services/tests/servicestests/src/com/android/server/vibrator/VibrationTest.java new file mode 100644 index 000000000000..b46929947fe4 --- /dev/null +++ b/services/tests/servicestests/src/com/android/server/vibrator/VibrationTest.java @@ -0,0 +1,46 @@ +/* + * Copyright (C) 2022 The Android Open Source Project + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +package com.android.server.vibrator; + +import static com.google.common.truth.Truth.assertThat; + +import static java.util.stream.Collectors.toList; + +import android.platform.test.annotations.Presubmit; + +import org.junit.Test; + +import java.util.Arrays; + +/** + * Tests for {@link Vibration}. + * + * Build/Install/Run: + * atest FrameworksServicesTests:VibrationTest + */ +@Presubmit +public class VibrationTest { + + @Test + public void status_hasUniqueProtoEnumValues() { + assertThat( + Arrays.stream(Vibration.Status.values()) + .map(Vibration.Status::getProtoEnumValue) + .collect(toList())) + .containsNoDuplicates(); + } +} diff --git a/services/tests/servicestests/src/com/android/server/vibrator/VibrationThreadTest.java b/services/tests/servicestests/src/com/android/server/vibrator/VibrationThreadTest.java index de5f6ed2ae5d..ca162efe0f6e 100644 --- a/services/tests/servicestests/src/com/android/server/vibrator/VibrationThreadTest.java +++ b/services/tests/servicestests/src/com/android/server/vibrator/VibrationThreadTest.java @@ -257,13 +257,18 @@ public class VibrationThreadTest { assertTrue(mThread.isRunningVibrationId(vibrationId)); assertTrue(mControllers.get(VIBRATOR_ID).isVibrating()); - conductor.notifyCancelled(Vibration.Status.CANCELLED_SUPERSEDED, /* immediate= */ false); + Vibration.EndInfo cancelVibrationInfo = new Vibration.EndInfo( + Vibration.Status.CANCELLED_SUPERSEDED, /* endedByUid= */ 1, + /* endedByUsage= */ VibrationAttributes.USAGE_ALARM); + conductor.notifyCancelled( + cancelVibrationInfo, + /* immediate= */ false); waitForCompletion(); assertFalse(mThread.isRunningVibrationId(vibrationId)); verify(mManagerHooks).noteVibratorOn(eq(UID), anyLong()); verify(mManagerHooks).noteVibratorOff(eq(UID)); - verifyCallbacksTriggered(vibrationId, Vibration.Status.CANCELLED_SUPERSEDED); + verifyCallbacksTriggered(vibrationId, cancelVibrationInfo); assertFalse(mControllers.get(VIBRATOR_ID).isVibrating()); List<Float> playedAmplitudes = fakeVibrator.getAmplitudes(); @@ -288,7 +293,9 @@ public class VibrationThreadTest { VibrationStepConductor conductor = startThreadAndDispatcher(vibrationId, effect); assertTrue(waitUntil(() -> !fakeVibrator.getAmplitudes().isEmpty(), TEST_TIMEOUT_MILLIS)); - conductor.notifyCancelled(Vibration.Status.CANCELLED_BY_USER, /* immediate= */ false); + conductor.notifyCancelled( + new Vibration.EndInfo(Vibration.Status.CANCELLED_BY_USER), + /* immediate= */ false); waitForCompletion(); verifyCallbacksTriggered(vibrationId, Vibration.Status.CANCELLED_BY_USER); @@ -319,7 +326,9 @@ public class VibrationThreadTest { assertTrue(waitUntil(() -> !fakeVibrator.getEffectSegments(vibrationId).isEmpty(), TEST_TIMEOUT_MILLIS)); - conductor.notifyCancelled(Vibration.Status.CANCELLED_BY_USER, /* immediate= */ false); + conductor.notifyCancelled( + new Vibration.EndInfo(Vibration.Status.CANCELLED_BY_USER), + /* immediate= */ false); waitForCompletion(); // PWLE size max was used to generate a single vibrate call with 10 segments. @@ -348,11 +357,13 @@ public class VibrationThreadTest { assertTrue(waitUntil(() -> !fakeVibrator.getEffectSegments(vibrationId).isEmpty(), TEST_TIMEOUT_MILLIS)); - conductor.notifyCancelled(Vibration.Status.CANCELLED_SUPERSEDED, /* immediate= */ false); + conductor.notifyCancelled( + new Vibration.EndInfo(Vibration.Status.CANCELLED_BY_SCREEN_OFF), + /* immediate= */ false); waitForCompletion(); // Composition size max was used to generate a single vibrate call with 10 primitives. - verifyCallbacksTriggered(vibrationId, Vibration.Status.CANCELLED_SUPERSEDED); + verifyCallbacksTriggered(vibrationId, Vibration.Status.CANCELLED_BY_SCREEN_OFF); assertFalse(mControllers.get(VIBRATOR_ID).isVibrating()); assertEquals(10, fakeVibrator.getEffectSegments(vibrationId).size()); } @@ -370,7 +381,9 @@ public class VibrationThreadTest { VibrationStepConductor conductor = startThreadAndDispatcher(vibrationId, effect); assertTrue(waitUntil(() -> !fakeVibrator.getAmplitudes().isEmpty(), TEST_TIMEOUT_MILLIS)); - conductor.notifyCancelled(Vibration.Status.CANCELLED_BY_USER, /* immediate= */ false); + conductor.notifyCancelled( + new Vibration.EndInfo(Vibration.Status.CANCELLED_BY_USER), + /* immediate= */ false); waitForCompletion(); verifyCallbacksTriggered(vibrationId, Vibration.Status.CANCELLED_BY_USER); @@ -394,7 +407,9 @@ public class VibrationThreadTest { assertTrue(waitUntil(() -> fakeVibrator.getEffectSegments(vibrationId).size() > 1, 5000 + TEST_TIMEOUT_MILLIS)); - conductor.notifyCancelled(Vibration.Status.CANCELLED_BY_USER, /* immediate= */ false); + conductor.notifyCancelled( + new Vibration.EndInfo(Vibration.Status.CANCELLED_BY_USER), + /* immediate= */ false); waitForCompletion(); verifyCallbacksTriggered(vibrationId, Vibration.Status.CANCELLED_BY_USER); @@ -414,6 +429,8 @@ public class VibrationThreadTest { public void vibrate_singleVibratorPredefinedCancel_cancelsVibrationImmediately() throws Exception { mVibratorProviders.get(VIBRATOR_ID).setCapabilities(IVibrator.CAP_COMPOSE_EFFECTS); + mVibratorProviders.get(VIBRATOR_ID).setSupportedPrimitives( + VibrationEffect.Composition.PRIMITIVE_CLICK); long vibrationId = 1; VibrationEffect effect = VibrationEffect.startComposition() @@ -431,7 +448,9 @@ public class VibrationThreadTest { // fail at waitForCompletion(vibrationThread) if the vibration not cancelled immediately. Thread cancellingThread = new Thread(() -> conductor.notifyCancelled( - Vibration.Status.CANCELLED_BY_SETTINGS_UPDATE, /* immediate= */ false)); + new Vibration.EndInfo( + Vibration.Status.CANCELLED_BY_SETTINGS_UPDATE), + /* immediate= */ false)); cancellingThread.start(); waitForCompletion(/* timeout= */ 50); @@ -458,7 +477,9 @@ public class VibrationThreadTest { // fail at waitForCompletion(vibrationThread) if the vibration not cancelled immediately. Thread cancellingThread = new Thread(() -> conductor.notifyCancelled( - Vibration.Status.CANCELLED_BY_SCREEN_OFF, /* immediate= */ false)); + new Vibration.EndInfo( + Vibration.Status.CANCELLED_BY_SCREEN_OFF), + /* immediate= */ false)); cancellingThread.start(); waitForCompletion(/* timeout= */ 50); @@ -519,7 +540,7 @@ public class VibrationThreadTest { startThreadAndDispatcher(vibrationId, effect); waitForCompletion(); - verify(mManagerHooks, never()).noteVibratorOn(eq(UID), anyLong()); + verify(mManagerHooks).noteVibratorOn(eq(UID), eq(0L)); verify(mManagerHooks, never()).noteVibratorOff(eq(UID)); verify(mControllerCallbacks, never()).onComplete(eq(VIBRATOR_ID), eq(vibrationId)); verifyCallbacksTriggered(vibrationId, Vibration.Status.IGNORED_UNSUPPORTED); @@ -530,6 +551,8 @@ public class VibrationThreadTest { public void vibrate_singleVibratorComposed_runsVibration() throws Exception { FakeVibratorControllerProvider fakeVibrator = mVibratorProviders.get(VIBRATOR_ID); fakeVibrator.setCapabilities(IVibrator.CAP_COMPOSE_EFFECTS); + fakeVibrator.setSupportedPrimitives(VibrationEffect.Composition.PRIMITIVE_CLICK, + VibrationEffect.Composition.PRIMITIVE_TICK); long vibrationId = 1; VibrationEffect effect = VibrationEffect.startComposition() @@ -559,7 +582,7 @@ public class VibrationThreadTest { startThreadAndDispatcher(vibrationId, effect); waitForCompletion(); - verify(mManagerHooks, never()).noteVibratorOn(eq(UID), anyLong()); + verify(mManagerHooks).noteVibratorOn(eq(UID), eq(0L)); verify(mManagerHooks, never()).noteVibratorOff(eq(UID)); verify(mControllerCallbacks, never()).onComplete(eq(VIBRATOR_ID), eq(vibrationId)); verifyCallbacksTriggered(vibrationId, Vibration.Status.IGNORED_UNSUPPORTED); @@ -570,6 +593,10 @@ public class VibrationThreadTest { public void vibrate_singleVibratorLargeComposition_splitsVibratorComposeCalls() { FakeVibratorControllerProvider fakeVibrator = mVibratorProviders.get(VIBRATOR_ID); fakeVibrator.setCapabilities(IVibrator.CAP_COMPOSE_EFFECTS); + fakeVibrator.setSupportedPrimitives( + VibrationEffect.Composition.PRIMITIVE_CLICK, + VibrationEffect.Composition.PRIMITIVE_TICK, + VibrationEffect.Composition.PRIMITIVE_SPIN); fakeVibrator.setCompositionSizeMax(2); long vibrationId = 1; @@ -809,6 +836,8 @@ public class VibrationThreadTest { mVibratorProviders.get(2).setCapabilities(IVibrator.CAP_AMPLITUDE_CONTROL); mVibratorProviders.get(3).setCapabilities(IVibrator.CAP_AMPLITUDE_CONTROL); mVibratorProviders.get(4).setCapabilities(IVibrator.CAP_COMPOSE_EFFECTS); + mVibratorProviders.get(4).setSupportedPrimitives( + VibrationEffect.Composition.PRIMITIVE_CLICK); long vibrationId = 1; VibrationEffect composed = VibrationEffect.startComposition() @@ -854,6 +883,8 @@ public class VibrationThreadTest { mockVibrators(1, 2, 3); mVibratorProviders.get(1).setCapabilities(IVibrator.CAP_AMPLITUDE_CONTROL); mVibratorProviders.get(2).setCapabilities(IVibrator.CAP_COMPOSE_EFFECTS); + mVibratorProviders.get(2).setSupportedPrimitives( + VibrationEffect.Composition.PRIMITIVE_CLICK); mVibratorProviders.get(3).setSupportedEffects(VibrationEffect.EFFECT_CLICK); long vibrationId = 1; @@ -902,7 +933,11 @@ public class VibrationThreadTest { long vibrationId = 1; mockVibrators(vibratorIds); mVibratorProviders.get(1).setCapabilities(IVibrator.CAP_COMPOSE_EFFECTS); + mVibratorProviders.get(1).setSupportedPrimitives( + VibrationEffect.Composition.PRIMITIVE_CLICK); mVibratorProviders.get(2).setCapabilities(IVibrator.CAP_COMPOSE_EFFECTS); + mVibratorProviders.get(2).setSupportedPrimitives( + VibrationEffect.Composition.PRIMITIVE_CLICK); when(mManagerHooks.prepareSyncedVibration(anyLong(), eq(vibratorIds))).thenReturn(true); when(mManagerHooks.triggerSyncedVibration(eq(vibrationId))).thenReturn(true); @@ -939,6 +974,8 @@ public class VibrationThreadTest { mockVibrators(vibratorIds); mVibratorProviders.get(1).setSupportedEffects(VibrationEffect.EFFECT_CLICK); mVibratorProviders.get(4).setCapabilities(IVibrator.CAP_COMPOSE_EFFECTS); + mVibratorProviders.get(4).setSupportedPrimitives( + VibrationEffect.Composition.PRIMITIVE_CLICK); when(mManagerHooks.prepareSyncedVibration(anyLong(), any())).thenReturn(true); when(mManagerHooks.triggerSyncedVibration(anyLong())).thenReturn(true); @@ -1125,7 +1162,9 @@ public class VibrationThreadTest { // fail at waitForCompletion(cancellingThread). Thread cancellingThread = new Thread( () -> conductor.notifyCancelled( - Vibration.Status.CANCELLED_BY_USER, /* immediate= */ false)); + new Vibration.EndInfo( + Vibration.Status.CANCELLED_BY_USER), + /* immediate= */ false)); cancellingThread.start(); // Cancelling the vibration should be fast and return right away, even if the thread is @@ -1143,6 +1182,8 @@ public class VibrationThreadTest { mockVibrators(1, 2); mVibratorProviders.get(1).setSupportedEffects(VibrationEffect.EFFECT_CLICK); mVibratorProviders.get(2).setCapabilities(IVibrator.CAP_COMPOSE_EFFECTS); + mVibratorProviders.get(2).setSupportedPrimitives( + VibrationEffect.Composition.PRIMITIVE_CLICK); long vibrationId = 1; CombinedVibration effect = CombinedVibration.startParallel() @@ -1163,13 +1204,15 @@ public class VibrationThreadTest { // fail at waitForCompletion(vibrationThread) if the vibration not cancelled immediately. Thread cancellingThread = new Thread( () -> conductor.notifyCancelled( - Vibration.Status.CANCELLED_SUPERSEDED, /* immediate= */ false)); + new Vibration.EndInfo( + Vibration.Status.CANCELLED_BY_SCREEN_OFF), + /* immediate= */ false)); cancellingThread.start(); waitForCompletion(/* timeout= */ 50); cancellingThread.join(); - verifyCallbacksTriggered(vibrationId, Vibration.Status.CANCELLED_SUPERSEDED); + verifyCallbacksTriggered(vibrationId, Vibration.Status.CANCELLED_BY_SCREEN_OFF); assertFalse(mControllers.get(1).isVibrating()); assertFalse(mControllers.get(2).isVibrating()); } @@ -1195,9 +1238,11 @@ public class VibrationThreadTest { // Run cancel in a separate thread so if VibrationThread.cancel blocks then this test should // fail at waitForCompletion(vibrationThread) if the vibration not cancelled immediately. - Thread cancellingThread = - new Thread(() -> conductor.notifyCancelled( - Vibration.Status.CANCELLED_BY_SCREEN_OFF, /* immediate= */ false)); + Thread cancellingThread = new Thread( + () -> conductor.notifyCancelled( + new Vibration.EndInfo( + Vibration.Status.CANCELLED_BY_SCREEN_OFF), + /* immediate= */ false)); cancellingThread.start(); waitForCompletion(/* timeout= */ 50); @@ -1266,7 +1311,7 @@ public class VibrationThreadTest { // Vibration completed but vibrator not yet released. verify(mManagerHooks, timeout(TEST_TIMEOUT_MILLIS)).onVibrationCompleted(eq(vibrationId), - eq(Vibration.Status.FINISHED)); + eq(new Vibration.EndInfo(Vibration.Status.FINISHED))); verify(mManagerHooks, never()).onVibrationThreadReleased(anyLong()); // Thread still running ramp down. @@ -1278,12 +1323,13 @@ public class VibrationThreadTest { // Will stop the ramp down right away. conductor.notifyCancelled( - Vibration.Status.CANCELLED_BY_SETTINGS_UPDATE, /* immediate= */ true); + new Vibration.EndInfo(Vibration.Status.CANCELLED_BY_SETTINGS_UPDATE), + /* immediate= */ true); waitForCompletion(); // Does not cancel already finished vibration, but releases vibrator. verify(mManagerHooks, never()).onVibrationCompleted(eq(vibrationId), - eq(Vibration.Status.CANCELLED_BY_SETTINGS_UPDATE)); + eq(new Vibration.EndInfo(Vibration.Status.CANCELLED_BY_SETTINGS_UPDATE))); verify(mManagerHooks).onVibrationThreadReleased(vibrationId); } @@ -1299,7 +1345,9 @@ public class VibrationThreadTest { VibrationStepConductor conductor = startThreadAndDispatcher(vibrationId, effect); assertTrue(waitUntil(() -> mControllers.get(VIBRATOR_ID).isVibrating(), TEST_TIMEOUT_MILLIS)); - conductor.notifyCancelled(Vibration.Status.CANCELLED_BY_USER, /* immediate= */ false); + conductor.notifyCancelled( + new Vibration.EndInfo(Vibration.Status.CANCELLED_BY_USER), + /* immediate= */ false); waitForCompletion(); verifyCallbacksTriggered(vibrationId, Vibration.Status.CANCELLED_BY_USER); @@ -1422,7 +1470,9 @@ public class VibrationThreadTest { VibrationStepConductor conductor2 = startThreadAndDispatcher(vibrationId2, effect2); // Effect2 won't complete on its own. Cancel it after a couple of repeats. Thread.sleep(150); // More than two TICKs. - conductor2.notifyCancelled(Vibration.Status.CANCELLED_BY_USER, /* immediate= */ false); + conductor2.notifyCancelled( + new Vibration.EndInfo(Vibration.Status.CANCELLED_BY_USER), + /* immediate= */ false); waitForCompletion(); startThreadAndDispatcher(vibrationId3, effect3); @@ -1431,7 +1481,9 @@ public class VibrationThreadTest { // Effect4 is a long oneshot, but it gets cancelled as fast as possible. long start4 = System.currentTimeMillis(); VibrationStepConductor conductor4 = startThreadAndDispatcher(vibrationId4, effect4); - conductor4.notifyCancelled(Vibration.Status.CANCELLED_SUPERSEDED, /* immediate= */ true); + conductor4.notifyCancelled( + new Vibration.EndInfo(Vibration.Status.CANCELLED_BY_SCREEN_OFF), + /* immediate= */ true); waitForCompletion(); long duration4 = System.currentTimeMillis() - start4; @@ -1469,7 +1521,7 @@ public class VibrationThreadTest { fakeVibrator.getEffectSegments(vibrationId3)); // Effect4: cancelled quickly. - verifyCallbacksTriggered(vibrationId4, Vibration.Status.CANCELLED_SUPERSEDED); + verifyCallbacksTriggered(vibrationId4, Vibration.Status.CANCELLED_BY_SCREEN_OFF); assertTrue("Tested duration=" + duration4, duration4 < 2000); // Effect5: normal oneshot. Don't worry about amplitude, as effect4 may or may not have @@ -1580,7 +1632,11 @@ public class VibrationThreadTest { } private void verifyCallbacksTriggered(long vibrationId, Vibration.Status expectedStatus) { - verify(mManagerHooks).onVibrationCompleted(eq(vibrationId), eq(expectedStatus)); + verifyCallbacksTriggered(vibrationId, new Vibration.EndInfo(expectedStatus)); + } + + private void verifyCallbacksTriggered(long vibrationId, Vibration.EndInfo expectedEndInfo) { + verify(mManagerHooks).onVibrationCompleted(eq(vibrationId), eq(expectedEndInfo)); verify(mManagerHooks).onVibrationThreadReleased(vibrationId); } diff --git a/services/tests/servicestests/src/com/android/server/vibrator/VibratorFrameworkStatsLoggerTest.java b/services/tests/servicestests/src/com/android/server/vibrator/VibratorFrameworkStatsLoggerTest.java new file mode 100644 index 000000000000..c1ab1db2732e --- /dev/null +++ b/services/tests/servicestests/src/com/android/server/vibrator/VibratorFrameworkStatsLoggerTest.java @@ -0,0 +1,127 @@ +/* + * Copyright (C) 2022 The Android Open Source Project + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +package com.android.server.vibrator; + +import static org.junit.Assert.assertFalse; +import static org.junit.Assert.assertTrue; + +import android.os.Handler; +import android.os.test.TestLooper; +import android.platform.test.annotations.Presubmit; + +import org.junit.Before; +import org.junit.Rule; +import org.junit.Test; +import org.mockito.junit.MockitoJUnit; +import org.mockito.junit.MockitoRule; + +/** + * Tests for {@link VibratorFrameworkStatsLogger}. + * + * Build/Install/Run: + * atest FrameworksServicesTests:VibratorFrameworkStatsLoggerTest + */ +@Presubmit +public class VibratorFrameworkStatsLoggerTest { + + @Rule public MockitoRule rule = MockitoJUnit.rule(); + + private TestLooper mTestLooper; + private VibratorFrameworkStatsLogger mLogger; + + @Before + public void setUp() { + mTestLooper = new TestLooper(); + } + + @Test + public void writeVibrationReportedAsync_afterMinInterval_writesRightAway() { + setUpLogger(/* minIntervalMillis= */ 10, /* queueMaxSize= */ 10); + + VibrationStats.StatsInfo firstStats = newEmptyStatsInfo(); + assertFalse(firstStats.isWritten()); + + mLogger.writeVibrationReportedAsync(firstStats); + mTestLooper.dispatchAll(); + assertTrue(firstStats.isWritten()); + } + + @Test + public void writeVibrationReportedAsync_rightAfterLogging_schedulesToRunAfterRemainingDelay() { + setUpLogger(/* minIntervalMillis= */ 100, /* queueMaxSize= */ 10); + + VibrationStats.StatsInfo firstStats = newEmptyStatsInfo(); + VibrationStats.StatsInfo secondStats = newEmptyStatsInfo(); + assertFalse(firstStats.isWritten()); + assertFalse(secondStats.isWritten()); + + // Write first message at current SystemClock.uptimeMillis + mLogger.writeVibrationReportedAsync(firstStats); + mTestLooper.dispatchAll(); + assertTrue(firstStats.isWritten()); + + // Second message is not written right away, it needs to wait the configured interval. + mLogger.writeVibrationReportedAsync(secondStats); + mTestLooper.dispatchAll(); + assertFalse(secondStats.isWritten()); + + // Second message is written after delay passes. + mTestLooper.moveTimeForward(100); + mTestLooper.dispatchAll(); + assertTrue(secondStats.isWritten()); + } + + @Test + public void writeVibrationReportedAsync_tooFast_logsUsingIntervalAndDropsMessagesFromQueue() { + setUpLogger(/* minIntervalMillis= */ 100, /* queueMaxSize= */ 2); + + VibrationStats.StatsInfo firstStats = newEmptyStatsInfo(); + VibrationStats.StatsInfo secondStats = newEmptyStatsInfo(); + VibrationStats.StatsInfo thirdStats = newEmptyStatsInfo(); + + mLogger.writeVibrationReportedAsync(firstStats); + mLogger.writeVibrationReportedAsync(secondStats); + mLogger.writeVibrationReportedAsync(thirdStats); + + // Only first message is logged. + mTestLooper.dispatchAll(); + assertTrue(firstStats.isWritten()); + assertFalse(secondStats.isWritten()); + assertFalse(thirdStats.isWritten()); + + // Wait one interval to check only the second one is logged. + mTestLooper.moveTimeForward(100); + mTestLooper.dispatchAll(); + assertTrue(secondStats.isWritten()); + assertFalse(thirdStats.isWritten()); + + // Wait a long interval to check the third one was dropped and will never be logged. + mTestLooper.moveTimeForward(1_000); + mTestLooper.dispatchAll(); + assertFalse(thirdStats.isWritten()); + } + + private void setUpLogger(int minIntervalMillis, int queueMaxSize) { + mLogger = new VibratorFrameworkStatsLogger(new Handler(mTestLooper.getLooper()), + minIntervalMillis, queueMaxSize); + } + + private static VibrationStats.StatsInfo newEmptyStatsInfo() { + return new VibrationStats.StatsInfo( + 0, 0, 0, Vibration.Status.FINISHED, new VibrationStats(), 0L); + } +} diff --git a/services/tests/servicestests/src/com/android/server/vibrator/VibratorManagerServiceTest.java b/services/tests/servicestests/src/com/android/server/vibrator/VibratorManagerServiceTest.java index 8a96febcd1e9..36bec750e3bc 100644 --- a/services/tests/servicestests/src/com/android/server/vibrator/VibratorManagerServiceTest.java +++ b/services/tests/servicestests/src/com/android/server/vibrator/VibratorManagerServiceTest.java @@ -34,6 +34,7 @@ import static org.mockito.Mockito.inOrder; import static org.mockito.Mockito.mock; import static org.mockito.Mockito.never; import static org.mockito.Mockito.spy; +import static org.mockito.Mockito.timeout; import static org.mockito.Mockito.times; import static org.mockito.Mockito.verify; import static org.mockito.Mockito.when; @@ -75,11 +76,13 @@ import android.os.vibrator.VibrationConfig; import android.os.vibrator.VibrationEffectSegment; import android.platform.test.annotations.Presubmit; import android.provider.Settings; +import android.util.SparseBooleanArray; import android.view.InputDevice; import androidx.test.InstrumentationRegistry; import com.android.internal.app.IBatteryStats; +import com.android.internal.util.FrameworkStatsLog; import com.android.internal.util.test.FakeSettingsProvider; import com.android.internal.util.test.FakeSettingsProviderRule; import com.android.server.LocalServices; @@ -148,6 +151,8 @@ public class VibratorManagerServiceTest { private IInputManager mIInputManagerMock; @Mock private IBatteryStats mBatteryStatsMock; + @Mock + private VibratorFrameworkStatsLogger mVibratorFrameworkStatsLoggerMock; private final Map<Integer, FakeVibratorControllerProvider> mVibratorProviders = new HashMap<>(); @@ -233,6 +238,11 @@ public class VibratorManagerServiceTest { } @Override + VibratorFrameworkStatsLogger getFrameworkStatsLogger(Handler handler) { + return mVibratorFrameworkStatsLoggerMock; + } + + @Override VibratorController createVibratorController(int vibratorId, VibratorController.OnVibrationCompleteListener listener) { return mVibratorProviders.get(vibratorId) @@ -806,11 +816,11 @@ public class VibratorManagerServiceTest { service, TEST_TIMEOUT_MILLIS)); VibrationEffect repeatingEffect = VibrationEffect.createWaveform( - new long[]{10_000, 10_000}, new int[]{128, 255}, 1); + new long[]{10, 10}, new int[]{128, 255}, 1); vibrate(service, repeatingEffect, NOTIFICATION_ATTRS); // VibrationThread will start this vibration async, so wait before checking it started. - assertTrue(waitUntil(s -> mVibratorProviders.get(1).getAllEffectSegments().size() > 1, + assertTrue(waitUntil(s -> mVibratorProviders.get(1).getAllEffectSegments().size() > 2, service, TEST_TIMEOUT_MILLIS)); // The second vibration should have recorded that the vibrators were turned on. @@ -916,7 +926,11 @@ public class VibratorManagerServiceTest { mockCapabilities(IVibratorManager.CAP_SYNC, IVibratorManager.CAP_PREPARE_COMPOSE); mockVibrators(1, 2); mVibratorProviders.get(1).setCapabilities(IVibrator.CAP_COMPOSE_EFFECTS); + mVibratorProviders.get(1).setSupportedPrimitives( + VibrationEffect.Composition.PRIMITIVE_CLICK); mVibratorProviders.get(2).setCapabilities(IVibrator.CAP_COMPOSE_EFFECTS); + mVibratorProviders.get(2).setSupportedPrimitives( + VibrationEffect.Composition.PRIMITIVE_CLICK); // Mock alarm intensity equals to default value to avoid scaling in this test. setUserSetting(Settings.System.ALARM_VIBRATION_INTENSITY, mVibrator.getDefaultVibrationIntensity(VibrationAttributes.USAGE_ALARM)); @@ -1078,6 +1092,8 @@ public class VibratorManagerServiceTest { FakeVibratorControllerProvider fakeVibrator = mVibratorProviders.get(1); fakeVibrator.setCapabilities(IVibrator.CAP_AMPLITUDE_CONTROL, IVibrator.CAP_COMPOSE_EFFECTS); + fakeVibrator.setSupportedPrimitives(VibrationEffect.Composition.PRIMITIVE_CLICK, + VibrationEffect.Composition.PRIMITIVE_TICK); VibratorManagerService service = createSystemReadyService(); vibrate(service, VibrationEffect.startComposition() @@ -1380,6 +1396,373 @@ public class VibratorManagerServiceTest { assertEquals(IExternalVibratorService.SCALE_MUTE, scale); } + @Test + public void frameworkStats_externalVibration_reportsAllMetrics() throws Exception { + mockVibrators(1); + mVibratorProviders.get(1).setCapabilities(IVibrator.CAP_EXTERNAL_CONTROL); + createSystemReadyService(); + + AudioAttributes audioAttrs = new AudioAttributes.Builder() + .setUsage(AudioAttributes.USAGE_ALARM) + .build(); + + ExternalVibration vib = new ExternalVibration(UID, PACKAGE_NAME, audioAttrs, + mock(IExternalVibrationController.class)); + mExternalVibratorService.onExternalVibrationStart(vib); + + Thread.sleep(10); + mExternalVibratorService.onExternalVibrationStop(vib); + + ArgumentCaptor<VibrationStats.StatsInfo> argumentCaptor = + ArgumentCaptor.forClass(VibrationStats.StatsInfo.class); + verify(mVibratorFrameworkStatsLoggerMock, timeout(TEST_TIMEOUT_MILLIS)) + .writeVibrationReportedAsync(argumentCaptor.capture()); + + VibrationStats.StatsInfo statsInfo = argumentCaptor.getValue(); + assertEquals(UID, statsInfo.uid); + assertEquals(FrameworkStatsLog.VIBRATION_REPORTED__VIBRATION_TYPE__EXTERNAL, + statsInfo.vibrationType); + assertEquals(VibrationAttributes.USAGE_ALARM, statsInfo.usage); + assertEquals(Vibration.Status.FINISHED.getProtoEnumValue(), statsInfo.status); + assertTrue(statsInfo.totalDurationMillis > 0); + assertTrue( + "Expected vibrator ON for at least 10ms, got " + statsInfo.vibratorOnMillis + "ms", + statsInfo.vibratorOnMillis >= 10); + assertEquals(2, statsInfo.halSetExternalControlCount); + } + + @Test + public void frameworkStats_waveformVibration_reportsAllMetrics() throws Exception { + mockVibrators(1); + mVibratorProviders.get(1).setCapabilities(IVibrator.CAP_AMPLITUDE_CONTROL); + + VibratorManagerService service = createSystemReadyService(); + vibrateAndWaitUntilFinished(service, + VibrationEffect.createWaveform(new long[] {0, 10, 20, 10}, -1), RINGTONE_ATTRS); + + verify(mVibratorFrameworkStatsLoggerMock, timeout(TEST_TIMEOUT_MILLIS)) + .writeVibratorStateOnAsync(eq(UID), anyLong()); + verify(mVibratorFrameworkStatsLoggerMock, timeout(TEST_TIMEOUT_MILLIS)) + .writeVibratorStateOffAsync(eq(UID)); + + ArgumentCaptor<VibrationStats.StatsInfo> argumentCaptor = + ArgumentCaptor.forClass(VibrationStats.StatsInfo.class); + verify(mVibratorFrameworkStatsLoggerMock, timeout(TEST_TIMEOUT_MILLIS)) + .writeVibrationReportedAsync(argumentCaptor.capture()); + + VibrationStats.StatsInfo metrics = argumentCaptor.getValue(); + assertEquals(UID, metrics.uid); + assertEquals(FrameworkStatsLog.VIBRATION_REPORTED__VIBRATION_TYPE__SINGLE, + metrics.vibrationType); + assertEquals(VibrationAttributes.USAGE_RINGTONE, metrics.usage); + assertEquals(Vibration.Status.FINISHED.getProtoEnumValue(), metrics.status); + assertTrue("Total duration was too low, " + metrics.totalDurationMillis + "ms", + metrics.totalDurationMillis >= 20); + assertTrue("Vibrator ON duration was too low, " + metrics.vibratorOnMillis + "ms", + metrics.vibratorOnMillis >= 20); + + // All unrelated metrics are empty. + assertEquals(0, metrics.repeatCount); + assertEquals(0, metrics.halComposeCount); + assertEquals(0, metrics.halComposePwleCount); + assertEquals(0, metrics.halPerformCount); + assertEquals(0, metrics.halSetExternalControlCount); + assertEquals(0, metrics.halCompositionSize); + assertEquals(0, metrics.halPwleSize); + assertNull(metrics.halSupportedCompositionPrimitivesUsed); + assertNull(metrics.halSupportedEffectsUsed); + assertNull(metrics.halUnsupportedCompositionPrimitivesUsed); + assertNull(metrics.halUnsupportedEffectsUsed); + + // Accommodate for ramping off config that might add extra setAmplitudes. + assertEquals(2, metrics.halOnCount); + assertTrue(metrics.halOffCount > 0); + assertTrue(metrics.halSetAmplitudeCount >= 2); + } + + @Test + public void frameworkStats_repeatingVibration_reportsAllMetrics() throws Exception { + mockVibrators(1); + mVibratorProviders.get(1).setCapabilities(IVibrator.CAP_AMPLITUDE_CONTROL); + + VibratorManagerService service = createSystemReadyService(); + vibrate(service, VibrationEffect.createWaveform(new long[] {10, 100}, 1), RINGTONE_ATTRS); + + verify(mVibratorFrameworkStatsLoggerMock, timeout(TEST_TIMEOUT_MILLIS)) + .writeVibratorStateOnAsync(eq(UID), anyLong()); + + // Wait for at least one loop before cancelling it. + Thread.sleep(100); + service.cancelVibrate(VibrationAttributes.USAGE_RINGTONE, service); + + verify(mVibratorFrameworkStatsLoggerMock, timeout(TEST_TIMEOUT_MILLIS)) + .writeVibratorStateOffAsync(eq(UID)); + + ArgumentCaptor<VibrationStats.StatsInfo> argumentCaptor = + ArgumentCaptor.forClass(VibrationStats.StatsInfo.class); + verify(mVibratorFrameworkStatsLoggerMock, timeout(TEST_TIMEOUT_MILLIS)) + .writeVibrationReportedAsync(argumentCaptor.capture()); + + VibrationStats.StatsInfo metrics = argumentCaptor.getValue(); + assertEquals(UID, metrics.uid); + assertEquals(FrameworkStatsLog.VIBRATION_REPORTED__VIBRATION_TYPE__REPEATED, + metrics.vibrationType); + assertEquals(VibrationAttributes.USAGE_RINGTONE, metrics.usage); + assertEquals(Vibration.Status.CANCELLED_BY_USER.getProtoEnumValue(), metrics.status); + assertTrue("Total duration was too low, " + metrics.totalDurationMillis + "ms", + metrics.totalDurationMillis >= 100); + assertTrue("Vibrator ON duration was too low, " + metrics.vibratorOnMillis + "ms", + metrics.vibratorOnMillis >= 100); + + // All unrelated metrics are empty. + assertTrue(metrics.repeatCount > 0); + assertEquals(0, metrics.halComposeCount); + assertEquals(0, metrics.halComposePwleCount); + assertEquals(0, metrics.halPerformCount); + assertEquals(0, metrics.halSetExternalControlCount); + assertEquals(0, metrics.halCompositionSize); + assertEquals(0, metrics.halPwleSize); + assertNull(metrics.halSupportedCompositionPrimitivesUsed); + assertNull(metrics.halSupportedEffectsUsed); + assertNull(metrics.halUnsupportedCompositionPrimitivesUsed); + assertNull(metrics.halUnsupportedEffectsUsed); + + // Accommodate for ramping off config that might add extra setAmplitudes. + assertTrue(metrics.halOnCount > 0); + assertTrue(metrics.halOffCount > 0); + assertTrue(metrics.halSetAmplitudeCount > 0); + } + + @Test + public void frameworkStats_prebakedAndComposedVibrations_reportsAllMetrics() throws Exception { + mockVibrators(1); + mVibratorProviders.get(1).setCapabilities(IVibrator.CAP_COMPOSE_EFFECTS); + mVibratorProviders.get(1).setSupportedEffects(VibrationEffect.EFFECT_CLICK); + mVibratorProviders.get(1).setSupportedPrimitives( + VibrationEffect.Composition.PRIMITIVE_TICK); + + VibratorManagerService service = createSystemReadyService(); + vibrateAndWaitUntilFinished(service, + VibrationEffect.startComposition() + .addEffect(VibrationEffect.createPredefined(VibrationEffect.EFFECT_CLICK)) + .addPrimitive(VibrationEffect.Composition.PRIMITIVE_TICK) + .addPrimitive(VibrationEffect.Composition.PRIMITIVE_TICK) + .addEffect(VibrationEffect.createPredefined(VibrationEffect.EFFECT_CLICK)) + .addEffect(VibrationEffect.createPredefined(VibrationEffect.EFFECT_TICK)) + .addPrimitive(VibrationEffect.Composition.PRIMITIVE_CLICK) + .addPrimitive(VibrationEffect.Composition.PRIMITIVE_CLICK) + .compose(), + ALARM_ATTRS); + + verify(mVibratorFrameworkStatsLoggerMock, timeout(TEST_TIMEOUT_MILLIS)) + .writeVibratorStateOnAsync(eq(UID), anyLong()); + verify(mVibratorFrameworkStatsLoggerMock, timeout(TEST_TIMEOUT_MILLIS)) + .writeVibratorStateOffAsync(eq(UID)); + + ArgumentCaptor<VibrationStats.StatsInfo> argumentCaptor = + ArgumentCaptor.forClass(VibrationStats.StatsInfo.class); + verify(mVibratorFrameworkStatsLoggerMock, timeout(TEST_TIMEOUT_MILLIS)) + .writeVibrationReportedAsync(argumentCaptor.capture()); + + VibrationStats.StatsInfo metrics = argumentCaptor.getValue(); + assertEquals(UID, metrics.uid); + assertEquals(FrameworkStatsLog.VIBRATION_REPORTED__VIBRATION_TYPE__SINGLE, + metrics.vibrationType); + assertEquals(VibrationAttributes.USAGE_ALARM, metrics.usage); + assertEquals(Vibration.Status.FINISHED.getProtoEnumValue(), metrics.status); + + // At least 4 effect/primitive played, 20ms each, plus configured fallback. + assertTrue("Total duration was too low, " + metrics.totalDurationMillis + "ms", + metrics.totalDurationMillis >= 80); + assertTrue("Vibrator ON duration was too low, " + metrics.vibratorOnMillis + "ms", + metrics.vibratorOnMillis >= 80); + + // Related metrics were collected. + assertEquals(2, metrics.halComposeCount); // TICK+TICK, then CLICK+CLICK + assertEquals(3, metrics.halPerformCount); // CLICK, TICK, then CLICK + assertEquals(4, metrics.halCompositionSize); // 2*TICK + 2*CLICK + // No repetitions in reported effect/primitive IDs. + assertArrayEquals(new int[] {VibrationEffect.Composition.PRIMITIVE_TICK}, + metrics.halSupportedCompositionPrimitivesUsed); + assertArrayEquals(new int[] {VibrationEffect.Composition.PRIMITIVE_CLICK}, + metrics.halUnsupportedCompositionPrimitivesUsed); + assertArrayEquals(new int[] {VibrationEffect.EFFECT_CLICK}, + metrics.halSupportedEffectsUsed); + assertArrayEquals(new int[] {VibrationEffect.EFFECT_TICK}, + metrics.halUnsupportedEffectsUsed); + + // All unrelated metrics are empty. + assertEquals(0, metrics.repeatCount); + assertEquals(0, metrics.halComposePwleCount); + assertEquals(0, metrics.halSetExternalControlCount); + assertEquals(0, metrics.halPwleSize); + + // Accommodate for ramping off config that might add extra setAmplitudes + // for the effect that plays the fallback instead of "perform". + assertTrue(metrics.halOnCount > 0); + assertTrue(metrics.halOffCount > 0); + assertTrue(metrics.halSetAmplitudeCount > 0); + } + + @Test + public void frameworkStats_interruptingVibrations_reportsAllMetrics() throws Exception { + mockVibrators(1); + VibratorManagerService service = createSystemReadyService(); + + vibrate(service, VibrationEffect.createOneShot(1_000, 128), HAPTIC_FEEDBACK_ATTRS); + + // VibrationThread will start this vibration async, so wait until vibration is triggered. + assertTrue(waitUntil(s -> !mVibratorProviders.get(1).getAllEffectSegments().isEmpty(), + service, TEST_TIMEOUT_MILLIS)); + + vibrateAndWaitUntilFinished(service, VibrationEffect.createOneShot(10, 255), ALARM_ATTRS); + + ArgumentCaptor<VibrationStats.StatsInfo> argumentCaptor = + ArgumentCaptor.forClass(VibrationStats.StatsInfo.class); + verify(mVibratorFrameworkStatsLoggerMock, timeout(TEST_TIMEOUT_MILLIS).times(2)) + .writeVibrationReportedAsync(argumentCaptor.capture()); + + VibrationStats.StatsInfo touchMetrics = argumentCaptor.getAllValues().get(0); + assertEquals(UID, touchMetrics.uid); + assertEquals(VibrationAttributes.USAGE_TOUCH, touchMetrics.usage); + assertEquals(Vibration.Status.CANCELLED_SUPERSEDED.getProtoEnumValue(), + touchMetrics.status); + assertTrue(touchMetrics.endedBySameUid); + assertEquals(VibrationAttributes.USAGE_ALARM, touchMetrics.endedByUsage); + assertEquals(-1, touchMetrics.interruptedUsage); + + VibrationStats.StatsInfo alarmMetrics = argumentCaptor.getAllValues().get(1); + assertEquals(UID, alarmMetrics.uid); + assertEquals(VibrationAttributes.USAGE_ALARM, alarmMetrics.usage); + assertEquals(Vibration.Status.FINISHED.getProtoEnumValue(), alarmMetrics.status); + assertFalse(alarmMetrics.endedBySameUid); + assertEquals(-1, alarmMetrics.endedByUsage); + assertEquals(VibrationAttributes.USAGE_TOUCH, alarmMetrics.interruptedUsage); + } + + @Test + public void frameworkStats_ignoredVibration_reportsStatus() throws Exception { + setUserSetting(Settings.System.RING_VIBRATION_INTENSITY, + Vibrator.VIBRATION_INTENSITY_OFF); + + mockVibrators(1); + VibratorManagerService service = createSystemReadyService(); + mRegisteredPowerModeListener.onLowPowerModeChanged(LOW_POWER_STATE); + + // Haptic feedback ignored in low power state + vibrateAndWaitUntilFinished(service, VibrationEffect.createOneShot(100, 128), + HAPTIC_FEEDBACK_ATTRS); + // Ringtone vibration user settings are off + vibrateAndWaitUntilFinished(service, VibrationEffect.createOneShot(200, 128), + RINGTONE_ATTRS); + + ArgumentCaptor<VibrationStats.StatsInfo> argumentCaptor = + ArgumentCaptor.forClass(VibrationStats.StatsInfo.class); + verify(mVibratorFrameworkStatsLoggerMock, timeout(TEST_TIMEOUT_MILLIS).times(2)) + .writeVibrationReportedAsync(argumentCaptor.capture()); + + VibrationStats.StatsInfo touchMetrics = argumentCaptor.getAllValues().get(0); + assertEquals(UID, touchMetrics.uid); + assertEquals(VibrationAttributes.USAGE_TOUCH, touchMetrics.usage); + assertEquals(Vibration.Status.IGNORED_FOR_POWER.getProtoEnumValue(), touchMetrics.status); + + VibrationStats.StatsInfo ringtoneMetrics = argumentCaptor.getAllValues().get(1); + assertEquals(UID, ringtoneMetrics.uid); + assertEquals(VibrationAttributes.USAGE_RINGTONE, ringtoneMetrics.usage); + assertEquals(Vibration.Status.IGNORED_FOR_SETTINGS.getProtoEnumValue(), + ringtoneMetrics.status); + + for (VibrationStats.StatsInfo metrics : argumentCaptor.getAllValues()) { + // Latencies are empty since vibrations never started + assertEquals(0, metrics.startLatencyMillis); + assertEquals(0, metrics.endLatencyMillis); + assertEquals(0, metrics.vibratorOnMillis); + + // All unrelated metrics are empty. + assertEquals(0, metrics.repeatCount); + assertEquals(0, metrics.halComposeCount); + assertEquals(0, metrics.halComposePwleCount); + assertEquals(0, metrics.halOffCount); + assertEquals(0, metrics.halOnCount); + assertEquals(0, metrics.halPerformCount); + assertEquals(0, metrics.halSetExternalControlCount); + assertEquals(0, metrics.halCompositionSize); + assertEquals(0, metrics.halPwleSize); + assertNull(metrics.halSupportedCompositionPrimitivesUsed); + assertNull(metrics.halSupportedEffectsUsed); + assertNull(metrics.halUnsupportedCompositionPrimitivesUsed); + assertNull(metrics.halUnsupportedEffectsUsed); + } + } + + @Test + public void frameworkStats_multiVibrators_reportsAllMetrics() throws Exception { + mockVibrators(1, 2); + mVibratorProviders.get(1).setCapabilities(IVibrator.CAP_COMPOSE_EFFECTS); + mVibratorProviders.get(1).setSupportedPrimitives( + VibrationEffect.Composition.PRIMITIVE_TICK); + mVibratorProviders.get(2).setSupportedEffects(VibrationEffect.EFFECT_TICK); + + VibratorManagerService service = createSystemReadyService(); + vibrateAndWaitUntilFinished(service, + CombinedVibration.startParallel() + .addVibrator(1, + VibrationEffect.startComposition() + .addPrimitive(VibrationEffect.Composition.PRIMITIVE_TICK) + .compose()) + .addVibrator(2, + VibrationEffect.createPredefined(VibrationEffect.EFFECT_TICK)) + .combine(), + NOTIFICATION_ATTRS); + + SparseBooleanArray expectedEffectsUsed = new SparseBooleanArray(); + expectedEffectsUsed.put(VibrationEffect.EFFECT_TICK, true); + + SparseBooleanArray expectedPrimitivesUsed = new SparseBooleanArray(); + expectedPrimitivesUsed.put(VibrationEffect.Composition.PRIMITIVE_TICK, true); + + verify(mVibratorFrameworkStatsLoggerMock, timeout(TEST_TIMEOUT_MILLIS)) + .writeVibratorStateOnAsync(eq(UID), anyLong()); + verify(mVibratorFrameworkStatsLoggerMock, timeout(TEST_TIMEOUT_MILLIS)) + .writeVibratorStateOffAsync(eq(UID)); + + ArgumentCaptor<VibrationStats.StatsInfo> argumentCaptor = + ArgumentCaptor.forClass(VibrationStats.StatsInfo.class); + verify(mVibratorFrameworkStatsLoggerMock, timeout(TEST_TIMEOUT_MILLIS)) + .writeVibrationReportedAsync(argumentCaptor.capture()); + + VibrationStats.StatsInfo metrics = argumentCaptor.getValue(); + assertEquals(UID, metrics.uid); + assertEquals(FrameworkStatsLog.VIBRATION_REPORTED__VIBRATION_TYPE__SINGLE, + metrics.vibrationType); + assertEquals(VibrationAttributes.USAGE_NOTIFICATION, metrics.usage); + assertEquals(Vibration.Status.FINISHED.getProtoEnumValue(), metrics.status); + assertTrue(metrics.totalDurationMillis >= 20); + + // vibratorOnMillis accumulates both vibrators, it's 20 for each constant. + assertEquals(40, metrics.vibratorOnMillis); + + // Related metrics were collected. + assertEquals(1, metrics.halComposeCount); + assertEquals(1, metrics.halPerformCount); + assertEquals(1, metrics.halCompositionSize); + assertEquals(2, metrics.halOffCount); + assertArrayEquals(new int[] {VibrationEffect.Composition.PRIMITIVE_TICK}, + metrics.halSupportedCompositionPrimitivesUsed); + assertArrayEquals(new int[] {VibrationEffect.EFFECT_TICK}, + metrics.halSupportedEffectsUsed); + + // All unrelated metrics are empty. + assertEquals(0, metrics.repeatCount); + assertEquals(0, metrics.halComposePwleCount); + assertEquals(0, metrics.halOnCount); + assertEquals(0, metrics.halSetAmplitudeCount); + assertEquals(0, metrics.halSetExternalControlCount); + assertEquals(0, metrics.halPwleSize); + assertNull(metrics.halUnsupportedCompositionPrimitivesUsed); + assertNull(metrics.halUnsupportedEffectsUsed); + } + private VibrationEffectSegment expectedPrebaked(int effectId) { return expectedPrebaked(effectId, VibrationEffect.EFFECT_STRENGTH_MEDIUM); } @@ -1429,6 +1812,20 @@ public class VibratorManagerServiceTest { mContextSpy.getContentResolver(), settingName, value, UserHandle.USER_CURRENT); } + private void vibrateAndWaitUntilFinished(VibratorManagerService service, VibrationEffect effect, + VibrationAttributes attrs) throws InterruptedException { + vibrateAndWaitUntilFinished(service, CombinedVibration.createParallel(effect), attrs); + } + + private void vibrateAndWaitUntilFinished(VibratorManagerService service, + CombinedVibration effect, VibrationAttributes attrs) throws InterruptedException { + Vibration vib = + service.vibrateInternal(UID, PACKAGE_NAME, effect, attrs, "some reason", service); + if (vib != null) { + vib.waitForEnd(); + } + } + private void vibrate(VibratorManagerService service, VibrationEffect effect, VibrationAttributes attrs) { vibrate(service, CombinedVibration.createParallel(effect), attrs); |