feat(logging): per-UID NDJSON on external storage
Move debug diagnostics off /data/local/tmp/teesim to /data/media/0/TEESimulator (visible at /sdcard/TEESimulator), so users can pull them without a root explorer. The logging code runs in the keystore SELinux domain, so a debug-only media_rw_data_file grant plus a debug-only diag.sh fragment gate the plane: diag.sh's presence is the signal service.sh (setup) and action.sh (export) test. customize.sh extracts diag.sh on debug installs or sweeps the dir on release, since the release keystore domain cannot remove it itself. Replace the per-call .bin parcel dumps (a fresh undecodable file per generateKey) with one NDJSON record per event on the UID's own file, carrying decoded fields plus the raw parcel as base64 for the offline parsers. computeIfAbsent makes per-UID writer creation atomic.
This commit is contained in:
Enginex0
@@ -202,6 +202,7 @@ androidComponents {
|
||||
val sourceModuleDir = rootProject.projectDir.resolve("module")
|
||||
from(sourceModuleDir) {
|
||||
exclude("module.prop") // Exclude the template file.
|
||||
exclude("diag.sh") // Debug-only diagnostic plane; included for debug below.
|
||||
}
|
||||
|
||||
// Copy and filter the module.prop template separately.
|
||||
@@ -214,8 +215,21 @@ androidComponents {
|
||||
)
|
||||
}
|
||||
|
||||
if (isDebug) {
|
||||
from(sourceModuleDir) { include("diag.sh") }
|
||||
}
|
||||
|
||||
// The destination for all the above 'from' operations.
|
||||
into(tempModuleDir)
|
||||
|
||||
if (isDebug) {
|
||||
doLast {
|
||||
// Debug-only: grant the keystore domain external-storage access; diag.sh
|
||||
// (shipped only in debug) carries the shell side of the diagnostic plane.
|
||||
tempModuleDir.get().asFile.resolve("sepolicy.rule")
|
||||
.appendText("\nallow keystore media_rw_data_file { dir file } *\n")
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
// Task 2: Zip the prepared files from the temporary directory.
|
||||
|
||||
@@ -6,13 +6,11 @@ import android.content.Context
|
||||
import android.content.ContextWrapper
|
||||
import android.os.Build
|
||||
import android.os.Looper
|
||||
import java.io.File
|
||||
import java.security.Security
|
||||
import org.bouncycastle.jce.provider.BouncyCastleProvider
|
||||
import org.matrix.TEESimulator.config.BootStateManager
|
||||
import org.matrix.TEESimulator.config.ConfigurationManager
|
||||
import org.matrix.TEESimulator.interception.keystore.AbstractKeystoreInterceptor
|
||||
import org.matrix.TEESimulator.interception.keystore.InterceptorUtils
|
||||
import org.matrix.TEESimulator.interception.keystore.Keystore2Interceptor
|
||||
import org.matrix.TEESimulator.interception.keystore.KeystoreInterceptor
|
||||
import org.matrix.TEESimulator.logging.SystemLogger
|
||||
@@ -41,7 +39,6 @@ object App {
|
||||
}
|
||||
|
||||
try {
|
||||
purgeDebugDiagnostics()
|
||||
prepareEnvironment()
|
||||
|
||||
// Spoof boot-state props before any hook attaches, so keystore2's
|
||||
@@ -74,41 +71,6 @@ object App {
|
||||
}
|
||||
}
|
||||
|
||||
/**
|
||||
* Release builds never emit diagnostics. Sweep anything a prior debug install left behind so it
|
||||
* cannot act as a detection artifact: the `.bin` dumps in the world-readable temp dir, and the
|
||||
* per-UID diagnostic logs under the config dir.
|
||||
*/
|
||||
private fun purgeDebugDiagnostics() {
|
||||
if (SystemLogger.isDebugBuild) return
|
||||
// .bin dumps and per-UID logs now share the diagnostic dir.
|
||||
purgeStale(File(InterceptorUtils.DIAGNOSTIC_DIR), InterceptorUtils.DIAGNOSTIC_DIR) { name ->
|
||||
name.startsWith("teesim-") &&
|
||||
(name.endsWith(".bin") || name.endsWith(".log") || name.endsWith(".log.1"))
|
||||
}
|
||||
// Older debug installs wrote dumps loose in /data/local/tmp and per-UID logs under the
|
||||
// module config dir; sweep both legacy locations so upgrading to a release build leaves
|
||||
// nothing behind.
|
||||
purgeStale(File("/data/local/tmp"), "/data/local/tmp") { name ->
|
||||
name.startsWith("teesim-") && name.endsWith(".bin")
|
||||
}
|
||||
purgeStale(File("${ConfigurationManager.CONFIG_PATH}/logs"), "legacy per-UID log dir") { name ->
|
||||
name.startsWith("teesim-uid-") && (name.endsWith(".log") || name.endsWith(".log.1"))
|
||||
}
|
||||
}
|
||||
|
||||
/**
|
||||
* Deletes matching files in [dir], logging a single once-per-boot audit line if any existed.
|
||||
*/
|
||||
private fun purgeStale(dir: File, label: String, matches: (String) -> Boolean) {
|
||||
val stale = dir.listFiles { _, name -> matches(name) } ?: return
|
||||
if (stale.isEmpty()) return
|
||||
stale.forEach { runCatching { it.delete() } }
|
||||
// warning() bypasses the rate limiter, so this once-per-boot audit line survives the noisy
|
||||
// startup window.
|
||||
SystemLogger.warning("Purged ${stale.size} stale debug diagnostic(s) from $label")
|
||||
}
|
||||
|
||||
/** Initializes the necessary Android framework internals to satisfy KeyStore requirements. */
|
||||
private fun prepareEnvironment() {
|
||||
// 1. Prepare Main Looper
|
||||
|
||||
+6
-12
@@ -19,13 +19,6 @@ data class KeyIdentifier(val uid: Int, val alias: String)
|
||||
/** A collection of utility functions to support binder interception. */
|
||||
object InterceptorUtils {
|
||||
|
||||
/**
|
||||
* Dedicated subfolder for the debug-only diagnostic `.bin` dumps. Keeping them out of the
|
||||
* world-readable `/data/local/tmp` root means they no longer litter a directory shared with
|
||||
* every other tool, and the release purge can sweep the whole folder in one shot.
|
||||
*/
|
||||
const val DIAGNOSTIC_DIR = "/data/local/tmp/teesim"
|
||||
|
||||
private const val EX_SERVICE_SPECIFIC = -8
|
||||
|
||||
private const val FLAT_STRIDE_HEADER = 12
|
||||
@@ -127,24 +120,25 @@ object InterceptorUtils {
|
||||
return BinderInterceptor.TransactionResult.OverrideReply(parcel)
|
||||
}
|
||||
|
||||
/** Correlates a captured reply parcel to the app that triggered it, for [createTypedObjectReply]. */
|
||||
data class ReplyDiagnostic(val uid: Int, val txId: Long?, val event: String)
|
||||
|
||||
/** Creates an `OverrideReply` parcel containing a Parcelable object. */
|
||||
fun <T : Parcelable?> createTypedObjectReply(
|
||||
obj: T,
|
||||
flags: Int = 0,
|
||||
diagnosticTag: String? = null,
|
||||
diagnostic: ReplyDiagnostic? = null,
|
||||
): BinderInterceptor.TransactionResult.OverrideReply {
|
||||
val parcel =
|
||||
Parcel.obtain().apply {
|
||||
writeNoException()
|
||||
writeTypedObject(obj, flags)
|
||||
}
|
||||
if (diagnosticTag != null && SystemLogger.isDebugBuild) {
|
||||
if (diagnostic != null && SystemLogger.isUidLogged(diagnostic.uid)) {
|
||||
val savedPos = parcel.dataPosition()
|
||||
val wire = parcel.marshall()
|
||||
parcel.setDataPosition(savedPos)
|
||||
val path = "$DIAGNOSTIC_DIR/teesim-$diagnosticTag.bin"
|
||||
runCatching { java.io.File(path).apply { parentFile?.mkdirs() }.writeBytes(wire) }
|
||||
SystemLogger.debug("[$diagnosticTag] reply len=${wire.size} path=$path")
|
||||
SystemLogger.uidLogRaw(diagnostic.uid, diagnostic.txId, diagnostic.event, "len=${wire.size}", wire)
|
||||
}
|
||||
return BinderInterceptor.TransactionResult.OverrideReply(parcel)
|
||||
}
|
||||
|
||||
+4
-9
@@ -527,16 +527,11 @@ class KeyMintSecurityLevelInterceptor(
|
||||
callingPid: Int,
|
||||
data: Parcel,
|
||||
): TransactionResult {
|
||||
if (SystemLogger.isDebugBuild) {
|
||||
if (SystemLogger.isUidLogged(callingUid)) {
|
||||
val savedPos = data.dataPosition()
|
||||
val req = data.marshall()
|
||||
data.setDataPosition(savedPos)
|
||||
val path =
|
||||
"${InterceptorUtils.DIAGNOSTIC_DIR}/teesim-gen-mode-req-uid${callingUid}-tx${txId}-${System.nanoTime()}.bin"
|
||||
runCatching { java.io.File(path).apply { parentFile?.mkdirs() }.writeBytes(req) }
|
||||
SystemLogger.debug(
|
||||
"[gen-mode-req] uid=$callingUid txId=$txId len=${req.size} path=$path"
|
||||
)
|
||||
SystemLogger.uidLogRaw(callingUid, txId, "genkey-request", "len=${req.size}", req)
|
||||
}
|
||||
val oversized = data.dataSize() > MAX_ALIAS_LENGTH
|
||||
|
||||
@@ -881,7 +876,7 @@ class KeyMintSecurityLevelInterceptor(
|
||||
|
||||
return InterceptorUtils.createTypedObjectReply(
|
||||
metadata,
|
||||
diagnosticTag = "gen-mode-sym-uid$callingUid-tx$txId",
|
||||
diagnostic = InterceptorUtils.ReplyDiagnostic(callingUid, txId, "genkey-reply-sym"),
|
||||
)
|
||||
}
|
||||
|
||||
@@ -996,7 +991,7 @@ class KeyMintSecurityLevelInterceptor(
|
||||
|
||||
return InterceptorUtils.createTypedObjectReply(
|
||||
response.metadata,
|
||||
diagnosticTag = "gen-mode-asym-uid$callingUid-tx$txId",
|
||||
diagnostic = InterceptorUtils.ReplyDiagnostic(callingUid, txId, "genkey-reply-asym"),
|
||||
)
|
||||
}
|
||||
|
||||
|
||||
@@ -1,15 +1,17 @@
|
||||
package org.matrix.TEESimulator.logging
|
||||
|
||||
import android.util.Base64
|
||||
import android.util.Log
|
||||
import java.io.BufferedWriter
|
||||
import java.io.File
|
||||
import java.io.FileWriter
|
||||
import java.text.SimpleDateFormat
|
||||
import java.util.Date
|
||||
import java.util.Locale
|
||||
import java.time.Instant
|
||||
import java.time.ZoneId
|
||||
import java.time.format.DateTimeFormatter
|
||||
import java.util.concurrent.ConcurrentHashMap
|
||||
import java.util.concurrent.atomic.AtomicInteger
|
||||
import java.util.concurrent.atomic.AtomicLong
|
||||
import org.json.JSONObject
|
||||
import org.matrix.TEESimulator.BuildConfig
|
||||
import org.matrix.TEESimulator.config.ConfigurationManager
|
||||
|
||||
@@ -141,18 +143,17 @@ object SystemLogger {
|
||||
ConfigurationManager.getPackagesForUid(uid).firstOrNull() ?: "uid:$uid"
|
||||
|
||||
/**
|
||||
* Emits one structured diagnostic record for a targeted [uid] as `[<pkg> tx=<txId>] <event>:
|
||||
* <detail>`. The record is mirrored to logcat and appended to that UID's own file. In-scope
|
||||
* records bypass the global rate limiter — a targeted app's traffic is already volume-bounded,
|
||||
* and dropping a line mid-probe would corrupt the very trace we are trying to read. No-op for
|
||||
* untargeted UIDs and in release builds.
|
||||
* Emits one structured diagnostic record for a targeted [uid]. The human form
|
||||
* `[<pkg> tx=<txId>] <event>: <detail>` goes to logcat; the file sink receives one NDJSON object
|
||||
* per line under that UID's own file. In-scope records bypass the global rate limiter: a
|
||||
* targeted app's traffic is already volume-bounded, and dropping a line mid-probe would corrupt
|
||||
* the very trace we are trying to read. No-op for untargeted UIDs and in release builds.
|
||||
*/
|
||||
fun uidLog(uid: Int, txId: Long?, event: String, detail: String) {
|
||||
if (!isUidLogged(uid)) return
|
||||
val correlation = txId?.let { " tx=$it" } ?: ""
|
||||
val line = "[${label(uid)}$correlation] $event: $detail"
|
||||
Log.d(TAG, line)
|
||||
runCatching { uidWriter(uid).append(line) }
|
||||
Log.d(TAG, "[${label(uid)}$correlation] $event: $detail")
|
||||
runCatching { uidWriter(uid).append(jsonRecord(uid, txId, event, detail, null)) }
|
||||
}
|
||||
|
||||
/** Lazy [uidLog]: [detail] is only built for targeted UIDs in debug builds. */
|
||||
@@ -161,35 +162,88 @@ object SystemLogger {
|
||||
uidLog(uid, txId, event, detail())
|
||||
}
|
||||
|
||||
// Co-located with the .bin dumps in InterceptorUtils.DIAGNOSTIC_DIR so every debug artifact sits
|
||||
// in one adb-pullable dir; release builds purge it (see App.purgeDebugDiagnostics).
|
||||
private val uidLogDir = File("/data/local/tmp/teesim")
|
||||
/**
|
||||
* [uidLog] plus the exact wire bytes that produced the event, base64 (NO_WRAP) in a `raw_b64`
|
||||
* field. This is the structured replacement for the per-call `.bin` parcel dumps: one NDJSON
|
||||
* line on the per-UID file instead of a fresh undecodable file per transaction, with the raw
|
||||
* parcel still recoverable for offline parsers.
|
||||
*/
|
||||
fun uidLogRaw(uid: Int, txId: Long?, event: String, detail: String, raw: ByteArray) {
|
||||
if (!isUidLogged(uid)) return
|
||||
val correlation = txId?.let { " tx=$it" } ?: ""
|
||||
Log.d(TAG, "[${label(uid)}$correlation] $event: $detail (raw ${raw.size}B)")
|
||||
runCatching {
|
||||
val encoded = Base64.encodeToString(raw, Base64.NO_WRAP)
|
||||
uidWriter(uid).append(jsonRecord(uid, txId, event, detail, encoded))
|
||||
}
|
||||
}
|
||||
|
||||
/**
|
||||
* External-storage root for every debug diagnostic. `/data/media/0/TEESimulator` is the
|
||||
* in-namespace backing path the keystore domain can reach; a normal file manager sees the same
|
||||
* files at `/sdcard/TEESimulator`. Release builds never write here and purge it on boot
|
||||
* (App.purgeDebugDiagnostics). The domain reaches it via a debug-only media_rw_data_file
|
||||
* sepolicy grant, and service.sh pre-creates the directory.
|
||||
*/
|
||||
const val DIAGNOSTIC_DIR = "/data/media/0/TEESimulator"
|
||||
|
||||
private val uidLogDir = File(DIAGNOSTIC_DIR)
|
||||
private const val UID_LOG_MAX_BYTES = 4L * 1024 * 1024
|
||||
private val uidWriters = ConcurrentHashMap<Int, UidLogFile>()
|
||||
|
||||
private fun uidWriter(uid: Int): UidLogFile = uidWriters.getOrPut(uid) { UidLogFile(uid, uidLogDir) }
|
||||
private val recordClock =
|
||||
DateTimeFormatter.ofPattern("MM-dd HH:mm:ss.SSS").withZone(ZoneId.systemDefault())
|
||||
|
||||
private fun jsonRecord(
|
||||
uid: Int,
|
||||
txId: Long?,
|
||||
event: String,
|
||||
detail: String,
|
||||
rawB64: String?,
|
||||
): String =
|
||||
JSONObject()
|
||||
.apply {
|
||||
put("ts", recordClock.format(Instant.now()))
|
||||
put("uid", uid)
|
||||
put("pkg", label(uid))
|
||||
txId?.let { put("tx", it) }
|
||||
put("event", event)
|
||||
put("detail", detail)
|
||||
rawB64?.let { put("raw_b64", it) }
|
||||
}
|
||||
.toString()
|
||||
|
||||
private fun uidWriter(uid: Int): UidLogFile =
|
||||
uidWriters.computeIfAbsent(uid) { key ->
|
||||
UidLogFile(key, uidLogDir).also { file ->
|
||||
val packages =
|
||||
ConfigurationManager.getPackagesForUid(key).joinToString().ifEmpty { "<unresolved>" }
|
||||
runCatching {
|
||||
file.append(jsonRecord(key, null, "session", "packages=[$packages]", null))
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
/**
|
||||
* An append-only diagnostic file for a single UID at `<logDir>/teesim-uid-<uid>.log`, rotated
|
||||
* once to `.log.1` at [UID_LOG_MAX_BYTES]. Writes are synchronised because the keystore binder
|
||||
* pool is multi-threaded, and every operation is wrapped so a logging fault can never propagate
|
||||
* into the daemon. Created only on the debug-gated path, so release builds never touch this dir.
|
||||
* Append-only NDJSON sink for a single UID at `<logDir>/teesim-uid-<uid>.ndjson`, rotated once
|
||||
* to `.ndjson.1` at [UID_LOG_MAX_BYTES]; one JSON object per line. Writes are synchronised
|
||||
* because the keystore binder pool is multi-threaded, and every operation is wrapped so a
|
||||
* logging fault can never propagate into the daemon. Created only on the debug-gated path.
|
||||
*/
|
||||
private class UidLogFile(private val uid: Int, private val logDir: File) {
|
||||
private val primary = File(logDir, "teesim-uid-$uid.log")
|
||||
private val rotated = File(logDir, "teesim-uid-$uid.log.1")
|
||||
private val clock = SimpleDateFormat("MM-dd HH:mm:ss.SSS", Locale.US)
|
||||
private class UidLogFile(uid: Int, private val logDir: File) {
|
||||
private val primary = File(logDir, "teesim-uid-$uid.ndjson")
|
||||
private val rotated = File(logDir, "teesim-uid-$uid.ndjson.1")
|
||||
private var writer: BufferedWriter? = null
|
||||
private var size = 0L
|
||||
|
||||
@Synchronized
|
||||
fun append(message: String) {
|
||||
fun append(jsonLine: String) {
|
||||
runCatching {
|
||||
val out = writer ?: open()
|
||||
val line = "${clock.format(Date())} $message\n"
|
||||
out.write(line)
|
||||
out.write(jsonLine)
|
||||
out.write("\n")
|
||||
out.flush()
|
||||
size += line.length
|
||||
size += jsonLine.length + 1
|
||||
if (size >= UID_LOG_MAX_BYTES) rotate()
|
||||
}
|
||||
}
|
||||
@@ -199,12 +253,6 @@ object SystemLogger {
|
||||
val out = BufferedWriter(FileWriter(primary, /* append = */ true))
|
||||
writer = out
|
||||
size = primary.length()
|
||||
val packages =
|
||||
ConfigurationManager.getPackagesForUid(uid).joinToString().ifEmpty { "<unresolved>" }
|
||||
val header = "${clock.format(Date())} === session uid=$uid packages=[$packages] ===\n"
|
||||
out.write(header)
|
||||
out.flush()
|
||||
size += header.length
|
||||
return out
|
||||
}
|
||||
|
||||
|
||||
Reference in New Issue
Block a user