Add battery logging.

app/src/main/java/org/thoughtcrime/securesms/ApplicationContext.java

@@ -114,6 +114,7 @@ import org.thoughtcrime.securesms.service.webrtc.ActiveCallManager;
 import org.thoughtcrime.securesms.service.webrtc.AndroidTelecomUtil;
 import org.thoughtcrime.securesms.storage.StorageSyncHelper;
 import org.thoughtcrime.securesms.util.AppStartup;
+import org.thoughtcrime.securesms.util.BatterySnapshotTracker;
 import org.thoughtcrime.securesms.util.DeviceProperties;
 import org.thoughtcrime.securesms.util.DynamicTheme;
 import org.thoughtcrime.securesms.util.Environment;
@@ -259,6 +260,8 @@ public class ApplicationContext extends Application implements AppForegroundObse
     long startTime = System.currentTimeMillis();
     Log.i(TAG, "App is now visible. Battery: " + DeviceProperties.getBatteryLevel(this) + "% (charging: " + DeviceProperties.isCharging(this) + ")");
 
+    BatterySnapshotTracker.emit(this, "foreground");
+
     AppDependencies.getFrameRateTracker().start();
     AppDependencies.getMegaphoneRepository().onAppForegrounded();
     AppDependencies.getDeadlockDetector().start();
@@ -299,6 +302,7 @@ public class ApplicationContext extends Application implements AppForegroundObse
   @Override
   public void onBackground() {
     Log.i(TAG, "App is no longer visible.");
+    BatterySnapshotTracker.emit(this, "background");
     KeyCachingService.onAppBackgrounded(this);
     AppDependencies.getMessageNotifier().clearVisibleThread();
     AppDependencies.getFrameRateTracker().stop();

app/src/main/java/org/thoughtcrime/securesms/logsubmit/LogSectionBattery.kt

@@ -0,0 +1,75 @@
+package org.thoughtcrime.securesms.logsubmit
+
+import android.app.usage.UsageStatsManager
+import android.content.Context
+import android.net.TrafficStats
+import android.os.Build
+import android.os.PowerManager
+import android.os.Process
+import android.os.SystemClock
+import org.signal.core.util.bytes
+import org.thoughtcrime.securesms.util.BucketInfo
+import org.thoughtcrime.securesms.util.DeviceProperties
+import org.thoughtcrime.securesms.util.WakeLockUtil
+import java.util.Locale
+import java.util.concurrent.TimeUnit
+import kotlin.time.Duration.Companion.milliseconds
+
+/**
+ * A point-in-time summary of process resource usage relevant to battery consumption. The detailed
+ * time series lives in the regular logs (emitted by [org.thoughtcrime.securesms.util.BatterySnapshotTracker]);
+ * this section gives an at-a-glance summary accumulated since process start.
+ */
+class LogSectionBattery : LogSection {
+  override fun getTitle(): String {
+    return "BATTERY"
+  }
+
+  override fun getContent(context: Context): CharSequence {
+    val cpuMs = Process.getElapsedCpuTime()
+    val wakeLockMs = WakeLockUtil.getCumulativeHeldMs()
+    val rxBytes = TrafficStats.getUidRxBytes(Process.myUid())
+    val txBytes = TrafficStats.getUidTxBytes(Process.myUid())
+
+    val builder = StringBuilder()
+
+    if (Build.VERSION.SDK_INT >= 24) {
+      val uptimeMs = SystemClock.elapsedRealtime() - Process.getStartElapsedRealtime()
+      builder.append("Process uptime  : ").append(uptimeMs.milliseconds.toString()).append("\n")
+      builder.append("CPU time        : ").append(cpuMs).append("ms (").append(percent(cpuMs, uptimeMs)).append(" of uptime)\n")
+      builder.append("Wakelock time   : ").append(wakeLockMs).append("ms (").append(percent(wakeLockMs, uptimeMs)).append(" of uptime)\n")
+    } else {
+      builder.append("CPU time        : ").append(cpuMs).append("ms\n")
+      builder.append("Wakelock time   : ").append(wakeLockMs).append("ms\n")
+    }
+
+    builder.append("Active wakelocks: ").append(WakeLockUtil.getActiveLockCount()).append("\n")
+    builder.append("Network rx/tx   : ").append(rxBytes.bytes.toUnitString()).append(" / ").append(txBytes.bytes.toUnitString()).append("\n")
+    builder.append("Battery level   : ").append(DeviceProperties.getBatteryLevel(context)).append("%\n")
+    builder.append("Charge counter  : ").append(DeviceProperties.getBatteryChargeCounter(context)).append("µAh\n")
+    builder.append("Charging        : ").append(DeviceProperties.isCharging(context)).append("\n")
+
+    val powerManager = context.getSystemService(Context.POWER_SERVICE) as? PowerManager
+    if (powerManager != null) {
+      builder.append("Power save mode : ").append(powerManager.isPowerSaveMode).append("\n")
+      builder.append("Device idle     : ").append(powerManager.isDeviceIdleMode).append("\n")
+      builder.append("Interactive     : ").append(powerManager.isInteractive).append("\n")
+    }
+
+    if (Build.VERSION.SDK_INT >= 28) {
+      val usageStatsManager = context.getSystemService(Context.USAGE_STATS_SERVICE) as? UsageStatsManager
+      if (usageStatsManager != null) {
+        builder.append("Standby bucket  : ").append(BucketInfo.bucketToString(usageStatsManager.appStandbyBucket)).append("\n")
+      }
+    }
+
+    return builder
+  }
+
+  private fun percent(part: Long, whole: Long): String {
+    if (whole <= 0) {
+      return "n/a"
+    }
+    return String.format(Locale.US, "%.1f%%", 100.0 * part / whole)
+  }
+}

app/src/main/java/org/thoughtcrime/securesms/logsubmit/SubmitDebugLogRepository.java

@@ -85,6 +85,7 @@ public class SubmitDebugLogRepository {
     if (Build.VERSION.SDK_INT >= 28) {
       add(new LogSectionPower());
     }
+    add(new LogSectionBattery());
     add(new LogSectionNotifications());
     add(new LogSectionNotificationProfiles());
     add(new LogSectionExoPlayerPool());

app/src/main/java/org/thoughtcrime/securesms/messageprocessingalarm/RoutineMessageFetchReceiver.java

@@ -19,6 +19,7 @@ import org.thoughtcrime.securesms.dependencies.AppDependencies;
 import org.thoughtcrime.securesms.jobmanager.JobTracker;
 import org.thoughtcrime.securesms.jobs.MessageFetchJob;
 import org.signal.core.util.AppForegroundObserver;
+import org.thoughtcrime.securesms.util.BatterySnapshotTracker;
 import org.thoughtcrime.securesms.util.RemoteConfig;
 
 import java.util.Locale;
@@ -49,6 +50,8 @@ public final class RoutineMessageFetchReceiver extends BroadcastReceiver {
         return;
       }
 
+      BatterySnapshotTracker.emit(context, "routine");
+
       long foregroundDelayMs = RemoteConfig.getBackgroundMessageProcessForegroundDelay();
       long jobTimeout        = foregroundDelayMs + 200;
 

app/src/main/java/org/thoughtcrime/securesms/util/BatterySnapshotTracker.kt

@@ -0,0 +1,121 @@
+package org.thoughtcrime.securesms.util
+
+import android.app.usage.UsageStatsManager
+import android.content.Context
+import android.net.TrafficStats
+import android.os.Build
+import android.os.PowerManager
+import android.os.Process
+import android.os.SystemClock
+import org.signal.core.util.bytes
+import org.signal.core.util.logging.Log
+import java.util.Locale
+
+/**
+ * Records lightweight, delta-based snapshots of process resource usage that correlate with battery
+ * drain (CPU time, held wakelocks, network bytes, and consumed charge), along with the power-related
+ * device state at the time of sampling.
+ *
+ * Every value read here is a cheap, in-process syscall, so this is intended to be sampled only when
+ * the app is already awake for another reason (e.g. a routine background fetch or a foreground
+ * transition). It deliberately never schedules its own wakeups, which would themselves drain battery.
+ */
+object BatterySnapshotTracker {
+
+  private val TAG = Log.tag(BatterySnapshotTracker::class.java)
+
+  private var lastSample: Sample? = null
+
+  @JvmStatic
+  @Synchronized
+  fun emit(context: Context, trigger: String) {
+    val sample = Sample(
+      elapsedRealtimeMs = SystemClock.elapsedRealtime(),
+      cpuMs = Process.getElapsedCpuTime(),
+      rxBytes = TrafficStats.getUidRxBytes(Process.myUid()),
+      txBytes = TrafficStats.getUidTxBytes(Process.myUid()),
+      wakeLockMs = WakeLockUtil.getCumulativeHeldMs(),
+      chargeCounterUah = DeviceProperties.getBatteryChargeCounter(context)
+    )
+
+    val previous = lastSample
+    lastSample = sample
+
+    val state = describeState(context)
+
+    if (previous == null) {
+      Log.i(TAG, "[$trigger] Baseline established. $state")
+      return
+    }
+
+    val wallMs = sample.elapsedRealtimeMs - previous.elapsedRealtimeMs
+    if (wallMs <= 0) {
+      Log.w(TAG, "[$trigger] Non-positive interval ($wallMs ms). Skipping.")
+      return
+    }
+
+    val cpuDeltaMs = sample.cpuMs - previous.cpuMs
+    val wakeDeltaMs = sample.wakeLockMs - previous.wakeLockMs
+
+    Log.i(
+      TAG,
+      String.format(
+        Locale.US,
+        "[%s] Δ=%.1fm | cpu=+%dms(%.1f%%) | wakelock=+%dms(%.1f%%) | net=%s | chargeΔ=%s | %s",
+        trigger,
+        wallMs / 60000.0,
+        cpuDeltaMs,
+        100.0 * cpuDeltaMs / wallMs,
+        wakeDeltaMs,
+        100.0 * wakeDeltaMs / wallMs,
+        formatNet(previous, sample),
+        formatCharge(previous, sample),
+        state
+      )
+    )
+  }
+
+  private fun formatNet(previous: Sample, sample: Sample): String {
+    if (sample.rxBytes < 0 || sample.txBytes < 0 || previous.rxBytes < 0 || previous.txBytes < 0) {
+      return "unsupported"
+    }
+    val rx = sample.rxBytes - previous.rxBytes
+    val tx = sample.txBytes - previous.txBytes
+    return "+${(rx + tx).bytes.toUnitString()} (rx ${rx.bytes.toUnitString()} / tx ${tx.bytes.toUnitString()})"
+  }
+
+  private fun formatCharge(previous: Sample, sample: Sample): String {
+    if (sample.chargeCounterUah < 0 || previous.chargeCounterUah < 0) {
+      return "unsupported"
+    }
+    return "${sample.chargeCounterUah - previous.chargeCounterUah}µAh"
+  }
+
+  private fun describeState(context: Context): String {
+    val level = DeviceProperties.getBatteryLevel(context)
+    val charging = DeviceProperties.isCharging(context)
+
+    val powerManager = context.getSystemService(Context.POWER_SERVICE) as? PowerManager
+    val powerSave = powerManager?.isPowerSaveMode ?: false
+    val doze = powerManager?.isDeviceIdleMode ?: false
+    val interactive = powerManager?.isInteractive ?: false
+
+    val bucket = if (Build.VERSION.SDK_INT >= 28) {
+      val usageStatsManager = context.getSystemService(Context.USAGE_STATS_SERVICE) as? UsageStatsManager
+      usageStatsManager?.let { BucketInfo.bucketToString(it.appStandbyBucket) } ?: "unknown"
+    } else {
+      "n/a"
+    }
+
+    return "battery=$level% charging=$charging powerSave=$powerSave doze=$doze interactive=$interactive bucket=$bucket"
+  }
+
+  private data class Sample(
+    val elapsedRealtimeMs: Long,
+    val cpuMs: Long,
+    val rxBytes: Long,
+    val txBytes: Long,
+    val wakeLockMs: Long,
+    val chargeCounterUah: Int
+  )
+}

app/src/main/java/org/thoughtcrime/securesms/util/DeviceProperties.java

@@ -98,6 +98,20 @@ public final class DeviceProperties {
     return -1;
   }
 
+  /**
+   * Returns the remaining battery charge in microampere-hours (µAh), or -1 if unavailable. Unlike
+   * the battery level percentage, this has fine granularity and is well-suited to measuring drain
+   * between two points in time.
+   */
+  public static int getBatteryChargeCounter(@NonNull Context context) {
+    BatteryManager batteryManager = (BatteryManager) context.getSystemService(Context.BATTERY_SERVICE);
+    if (batteryManager != null) {
+      int value = batteryManager.getIntProperty(BatteryManager.BATTERY_PROPERTY_CHARGE_COUNTER);
+      return value > 0 ? value : -1;
+    }
+    return -1;
+  }
+
   /**
    * Returns whether the device is currently charging.
    */

app/src/main/java/org/thoughtcrime/securesms/util/WakeLockUtil.java

@@ -3,6 +3,7 @@ package org.thoughtcrime.securesms.util;
 import android.content.Context;
 import android.os.PowerManager;
 import android.os.PowerManager.WakeLock;
+import android.os.SystemClock;
 
 import androidx.annotation.NonNull;
 import androidx.annotation.Nullable;
@@ -10,10 +11,17 @@ import androidx.annotation.Nullable;
 import org.signal.core.util.logging.Log;
 import org.signal.core.util.ServiceUtil;
 
+import java.util.Map;
+import java.util.concurrent.ConcurrentHashMap;
+import java.util.concurrent.atomic.AtomicLong;
+
 public class WakeLockUtil {
 
   private static final String TAG = Log.tag(WakeLockUtil.class);
 
+  private static final Map<WakeLock, Acquisition> activeAcquisitions = new ConcurrentHashMap<>();
+  private static final AtomicLong                 cumulativeHeldMs   = new AtomicLong(0);
+
   /**
    * Run a runnable with a wake lock. Ensures that the lock is safely acquired and released.
    *
@@ -42,6 +50,8 @@ public class WakeLockUtil {
 
       wakeLock.acquire(timeout);
 
+      activeAcquisitions.put(wakeLock, new Acquisition(SystemClock.elapsedRealtime(), timeout));
+
       return wakeLock;
     } catch (Exception e) {
       Log.w(TAG, "Failed to acquire wakelock with tag: " + tag, e);
@@ -54,6 +64,11 @@ public class WakeLockUtil {
    */
   public static void release(@Nullable WakeLock wakeLock, @NonNull String tag) {
     tag = prefixTag(tag);
+
+    if (wakeLock != null) {
+      recordHeldTime(wakeLock);
+    }
+
     try {
       if (wakeLock == null) {
         Log.d(TAG, "Wakelock was null. Skipping. Tag: " + tag);
@@ -67,7 +82,51 @@ public class WakeLockUtil {
     }
   }
 
+  /**
+   * The cumulative time, in milliseconds, that wakelocks acquired through this class have been held
+   * since process start. Includes the in-progress duration of any currently-held locks.
+   */
+  public static long getCumulativeHeldMs() {
+    long total = cumulativeHeldMs.get();
+    long now   = SystemClock.elapsedRealtime();
+
+    for (Acquisition acquisition : activeAcquisitions.values()) {
+      total += acquisition.heldMs(now);
+    }
+
+    return total;
+  }
+
+  /**
+   * The number of wakelocks acquired through this class that are currently being tracked as held.
+   */
+  public static int getActiveLockCount() {
+    return activeAcquisitions.size();
+  }
+
+  private static void recordHeldTime(@NonNull WakeLock wakeLock) {
+    Acquisition acquisition = activeAcquisitions.remove(wakeLock);
+    if (acquisition != null) {
+      cumulativeHeldMs.addAndGet(acquisition.heldMs(SystemClock.elapsedRealtime()));
+    }
+  }
+
   private static String prefixTag(@NonNull String tag) {
     return tag.startsWith("signal:") ? tag : "signal:" + tag;
   }
+
+  private static final class Acquisition {
+    private final long acquiredAtMs;
+    private final long timeoutMs;
+
+    Acquisition(long acquiredAtMs, long timeoutMs) {
+      this.acquiredAtMs = acquiredAtMs;
+      this.timeoutMs    = timeoutMs;
+    }
+
+    long heldMs(long now) {
+      long elapsed = Math.max(0, now - acquiredAtMs);
+      return timeoutMs > 0 ? Math.min(elapsed, timeoutMs) : elapsed;
+    }
+  }
 }