Improve logging around memory usage.

This commit is contained in:
Greyson Parrelli 2023-07-07 14:41:23 -04:00 committed by Clark Chen
parent 500ae0c72e
commit 5ca025544e
6 changed files with 274 additions and 0 deletions

View file

@ -30,6 +30,7 @@ import com.google.android.gms.security.ProviderInstaller;
import org.conscrypt.Conscrypt;
import org.greenrobot.eventbus.EventBus;
import org.signal.aesgcmprovider.AesGcmProvider;
import org.signal.core.util.MemoryTracker;
import org.signal.core.util.concurrent.SignalExecutors;
import org.signal.core.util.logging.AndroidLogger;
import org.signal.core.util.logging.Log;
@ -237,6 +238,7 @@ public class ApplicationContext extends MultiDexApplication implements AppForegr
KeyCachingService.onAppForegrounded(this);
ApplicationDependencies.getShakeToReport().enable();
checkBuildExpiration();
MemoryTracker.start();
long lastForegroundTime = SignalStore.misc().getLastForegroundTime();
long currentTime = System.currentTimeMillis();
@ -260,6 +262,7 @@ public class ApplicationContext extends MultiDexApplication implements AppForegr
ApplicationDependencies.getFrameRateTracker().stop();
ApplicationDependencies.getShakeToReport().disable();
ApplicationDependencies.getDeadlockDetector().stop();
MemoryTracker.stop();
}
public PersistentLogger getPersistentLogger() {

View file

@ -0,0 +1,56 @@
package org.thoughtcrime.securesms.logsubmit
import android.content.Context
import android.os.Build
import org.signal.core.util.MemoryTracker
import org.signal.core.util.bytes
import org.signal.core.util.kibiBytes
import org.signal.core.util.roundedString
class LogSectionMemory : LogSection {
override fun getTitle(): String = "MEMORY"
override fun getContent(context: Context): CharSequence {
val appMemory = MemoryTracker.getAppJvmHeapUsage()
val nativeMemory = MemoryTracker.getSystemNativeMemoryUsage(context)
var base = """
-- App JVM Heap
Used : ${appMemory.usedBytes.byteDisplay()}
Free : ${appMemory.freeBytes.byteDisplay()}
Current Total: ${appMemory.currentTotalBytes.byteDisplay()}
Max Possible : ${appMemory.maxPossibleBytes.byteDisplay()}
-- System Native Memory
Used : ${nativeMemory.usedBytes.byteDisplay()}
Free : ${nativeMemory.freeBytes.byteDisplay()}
Total : ${nativeMemory.totalBytes.byteDisplay()}
Low Memory Threshold: ${nativeMemory.lowMemoryThreshold.byteDisplay()}
Low Memory? : ${nativeMemory.lowMemory}
""".trimIndent()
if (Build.VERSION.SDK_INT >= 23) {
val detailedMemory = MemoryTracker.getDetailedMemoryStats()
base += "\n\n"
base += """
-- Detailed Memory (API 23+)
App JVM Heap Usage : ${detailedMemory.appJavaHeapUsageKb?.kbDisplay()}
App Native Heap Usage: ${detailedMemory.appNativeHeapUsageKb?.kbDisplay()}
Code Usage : ${detailedMemory.codeUsageKb?.kbDisplay()}
Graphics Usage : ${detailedMemory.graphicsUsageKb?.kbDisplay()}
Stack Usage : ${detailedMemory.stackUsageKb?.kbDisplay()}
Other Usage : ${detailedMemory.appOtherUsageKb?.kbDisplay()}
""".trimIndent()
}
return base
}
private fun Long.byteDisplay(): String {
return "$this bytes (${bytes.inMebiBytes.roundedString(2)} MiB)"
}
private fun Long.kbDisplay(): String {
return "$this KiB (${kibiBytes.inMebiBytes.roundedString(2)} MiB)"
}
}

View file

@ -75,6 +75,7 @@ public class SubmitDebugLogRepository {
add(new LogSectionJobs());
add(new LogSectionConstraints());
add(new LogSectionCapabilities());
add(new LogSectionMemory());
add(new LogSectionLocalMetrics());
add(new LogSectionFeatureFlags());
add(new LogSectionPin());

View file

@ -0,0 +1,41 @@
/*
* Copyright 2023 Signal Messenger, LLC
* SPDX-License-Identifier: AGPL-3.0-only
*/
package org.signal.core.util
inline val Long.bytes: ByteSize
get() = ByteSize(this)
inline val Long.kibiBytes: ByteSize
get() = (this * 1024).bytes
inline val Long.mebiBytes: ByteSize
get() = (this * 1024).kibiBytes
inline val Long.gibiBytes: ByteSize
get() = (this * 1024).mebiBytes
class ByteSize(val bytes: Long) {
val inWholeBytes: Long
get() = bytes
val inWholeKibiBytes: Long
get() = bytes / 1024
val inWholeMebiBytes: Long
get() = inWholeKibiBytes / 1024
val inWholeGibiBytes: Long
get() = inWholeMebiBytes / 1024
val inKibiBytes: Float
get() = bytes / 1024f
val inMebiBytes: Float
get() = inKibiBytes / 1024f
val inGibiBytes: Float
get() = inMebiBytes / 1024f
}

View file

@ -0,0 +1,20 @@
/*
* Copyright 2023 Signal Messenger, LLC
* SPDX-License-Identifier: AGPL-3.0-only
*/
package org.signal.core.util
import kotlin.math.pow
import kotlin.math.round
/**
* Rounds a number to the specififed number of places. e.g.
*
* 1.123456f.roundedString(2) = 1.12
* 1.123456f.roundedString(5) = 1.12346
*/
fun Float.roundedString(places: Int): String {
val powerMultiplier = 10f.pow(places)
return (round(this * powerMultiplier) / powerMultiplier).toString()
}

View file

@ -0,0 +1,153 @@
/*
* Copyright 2023 Signal Messenger, LLC
* SPDX-License-Identifier: AGPL-3.0-only
*/
package org.signal.core.util
import android.app.ActivityManager
import android.content.Context
import android.os.Debug
import android.os.Handler
import androidx.annotation.RequiresApi
import org.signal.core.util.concurrent.SignalExecutors
import org.signal.core.util.logging.Log
import kotlin.time.Duration.Companion.milliseconds
import kotlin.time.Duration.Companion.seconds
object MemoryTracker {
private val TAG = Log.tag(MemoryTracker::class.java)
private val runtime: Runtime = Runtime.getRuntime()
private val activityMemoryInfo: ActivityManager.MemoryInfo = ActivityManager.MemoryInfo()
private val debugMemoryInfo: Debug.MemoryInfo = Debug.MemoryInfo()
private val handler: Handler = Handler(SignalExecutors.getAndStartHandlerThread("MemoryTracker", ThreadUtil.PRIORITY_BACKGROUND_THREAD).looper)
private val POLLING_INTERVAL = 5.seconds.inWholeMilliseconds
private var running = false
private lateinit var previousAppHeadUsage: AppHeapUsage
private var increaseMemoryCount = 0
@JvmStatic
fun start() {
Log.d(TAG, "Beginning memory monitoring.")
running = true
previousAppHeadUsage = getAppJvmHeapUsage()
increaseMemoryCount = 0
handler.postDelayed(this::poll, POLLING_INTERVAL)
}
@JvmStatic
fun stop() {
Log.d(TAG, "Ending memory monitoring.")
running = false
handler.removeCallbacksAndMessages(null)
}
fun poll() {
val currentHeapUsage = getAppJvmHeapUsage()
if (currentHeapUsage.currentTotalBytes != previousAppHeadUsage.currentTotalBytes) {
if (currentHeapUsage.currentTotalBytes > previousAppHeadUsage.currentTotalBytes) {
Log.d(TAG, "The system increased our app JVM heap from ${previousAppHeadUsage.currentTotalBytes.byteDisplay()} to ${currentHeapUsage.currentTotalBytes.byteDisplay()}")
} else {
Log.d(TAG, "The system decreased our app JVM heap from ${previousAppHeadUsage.currentTotalBytes.byteDisplay()} to ${currentHeapUsage.currentTotalBytes.byteDisplay()}")
}
}
if (currentHeapUsage.usedBytes >= previousAppHeadUsage.usedBytes) {
increaseMemoryCount++
} else {
Log.d(TAG, "Used memory has decreased from ${previousAppHeadUsage.usedBytes.byteDisplay()} to ${currentHeapUsage.usedBytes.byteDisplay()}")
increaseMemoryCount = 0
}
if (increaseMemoryCount > 0 && increaseMemoryCount % 5 == 0) {
Log.d(TAG, "Used memory has increased or stayed the same for the last $increaseMemoryCount intervals (${increaseMemoryCount * POLLING_INTERVAL.milliseconds.inWholeSeconds} seconds). Using: ${currentHeapUsage.usedBytes.byteDisplay()}, Free: ${currentHeapUsage.freeBytes.byteDisplay()}, CurrentTotal: ${currentHeapUsage.currentTotalBytes.byteDisplay()}, MaxPossible: ${currentHeapUsage.maxPossibleBytes.byteDisplay()}")
}
previousAppHeadUsage = currentHeapUsage
if (running) {
handler.postDelayed(this::poll, POLLING_INTERVAL)
}
}
/**
* Gives us basic memory usage data for our app JVM heap usage. Very fast, ~10 micros on an emulator.
*/
fun getAppJvmHeapUsage(): AppHeapUsage {
return AppHeapUsage(
freeBytes = runtime.freeMemory(),
currentTotalBytes = runtime.totalMemory(),
maxPossibleBytes = runtime.maxMemory()
)
}
/**
* This gives us details stats, but it takes an appreciable amount of time. On an emulator, it can take ~30ms.
* As a result, we don't want to be calling this regularly for most users.
*/
@RequiresApi(23)
fun getDetailedMemoryStats(): DetailedMemoryStats {
Debug.getMemoryInfo(debugMemoryInfo)
return DetailedMemoryStats(
appJavaHeapUsageKb = debugMemoryInfo.getMemoryStat("summary.java-heap")?.toLongOrNull(),
appNativeHeapUsageKb = debugMemoryInfo.getMemoryStat("summary.native-heap")?.toLongOrNull(),
codeUsageKb = debugMemoryInfo.getMemoryStat("summary.code")?.toLongOrNull(),
stackUsageKb = debugMemoryInfo.getMemoryStat("summary.stack")?.toLongOrNull(),
graphicsUsageKb = debugMemoryInfo.getMemoryStat("summary.graphics")?.toLongOrNull(),
appOtherUsageKb = debugMemoryInfo.getMemoryStat("summary.private-other")?.toLongOrNull()
)
}
fun getSystemNativeMemoryUsage(context: Context): NativeMemoryUsage {
val activityManager: ActivityManager = context.getSystemService(Context.ACTIVITY_SERVICE) as ActivityManager
activityManager.getMemoryInfo(activityMemoryInfo)
return NativeMemoryUsage(
freeBytes = activityMemoryInfo.availMem,
totalBytes = activityMemoryInfo.totalMem,
lowMemory = activityMemoryInfo.lowMemory,
lowMemoryThreshold = activityMemoryInfo.threshold
)
}
private fun Long.byteDisplay(): String {
return "$this (${this.bytes.inMebiBytes.roundedString(2)} MiB)"
}
data class AppHeapUsage(
/** The number of bytes that are free to use. */
val freeBytes: Long,
/** The current total number of bytes our app could use. This can increase over time as the system increases our allocation. */
val currentTotalBytes: Long,
/** The maximum number of bytes that our app could ever be given. */
val maxPossibleBytes: Long
) {
/** The number of bytes that our app is currently using. */
val usedBytes: Long
get() = currentTotalBytes - freeBytes
}
data class NativeMemoryUsage(
val freeBytes: Long,
val totalBytes: Long,
val lowMemory: Boolean,
val lowMemoryThreshold: Long
) {
val usedBytes: Long
get() = totalBytes - freeBytes
}
data class DetailedMemoryStats(
val appJavaHeapUsageKb: Long?,
val appNativeHeapUsageKb: Long?,
val codeUsageKb: Long?,
val graphicsUsageKb: Long?,
val stackUsageKb: Long?,
val appOtherUsageKb: Long?
)
}