feat(logging): UID-keyed attestation dossier
Add a debug-only per-UID diagnostic plane gated on BuildConfig.DEBUG. For apps in target.txt it records every keystore interaction and the forged attestation it produces to teesim-uid-<uid>.log: decoded cert chain (FORGE and PATCH paths), key params, keybox, and prop sources, with the calling UID threaded through the C++ binder hook and Rust certgen. Release builds stay silent (R8 strips the write plane and the runtime gate short-circuits). Adds --clear-logs to package.sh.
This commit is contained in:
Enginex0
@@ -403,7 +403,10 @@ void inspectAndRewriteTransaction(binder_transaction_data *txn_data) {
|
||||
uint64_t tx_id = ++g_transaction_id_counter;
|
||||
info.transaction_id = tx_id;
|
||||
|
||||
LOGV("[Hook] Hijacking Transaction %" PRIu64 " (Code: %u)", tx_id, txn_data->code);
|
||||
// tx_id is the same counter handed to the Kotlin interceptor, and sender_euid is the
|
||||
// calling app; together they correlate this native hijack with that UID's per-UID file.
|
||||
LOGV("[Hook] Hijacking Transaction %" PRIu64 " (Code: %u, uid=%u)", tx_id, txn_data->code,
|
||||
txn_data->sender_euid);
|
||||
|
||||
// Rewrite the destination to our Stub
|
||||
txn_data->target.ptr = reinterpret_cast<uintptr_t>(g_stub_instance->getWeakRefs());
|
||||
|
||||
@@ -74,24 +74,28 @@ object App {
|
||||
}
|
||||
|
||||
/**
|
||||
* Release builds never emit diagnostics. Sweep any `.bin` dumps a prior debug install left in
|
||||
* the world-readable temp dir so they can't act as a detection artifact for apps that probe
|
||||
* /data/local/tmp.
|
||||
* 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
|
||||
val stale =
|
||||
File("/data/local/tmp").listFiles { _, name ->
|
||||
name.startsWith("teesim-") && name.endsWith(".bin")
|
||||
} ?: return
|
||||
stale.forEach { runCatching { it.delete() } }
|
||||
if (stale.isNotEmpty()) {
|
||||
// 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 /data/local/tmp"
|
||||
)
|
||||
purgeStale(File("/data/local/tmp"), "/data/local/tmp") { name ->
|
||||
name.startsWith("teesim-") && name.endsWith(".bin")
|
||||
}
|
||||
purgeStale(File("${ConfigurationManager.CONFIG_PATH}/logs"), "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. */
|
||||
|
||||
@@ -234,6 +234,103 @@ object AttestationPatcher {
|
||||
}
|
||||
}
|
||||
|
||||
/** Reverse map of attestation tag number to its symbolic name, e.g. 704 -> "ROOT_OF_TRUST". */
|
||||
private val attestTagNames: Map<Int, String> by lazy {
|
||||
AttestationConstants::class
|
||||
.java
|
||||
.fields
|
||||
.filter { it.name.startsWith("TAG_") && it.type == Int::class.java }
|
||||
.associate { (it.get(null) as Int) to it.name.removePrefix("TAG_") }
|
||||
}
|
||||
|
||||
/**
|
||||
* Renders the full key-attestation extension of [cert] as a single structured line for the
|
||||
* diagnostic dossier, or null when the certificate carries no attestation extension. This is the
|
||||
* ground-truth view of what we actually emitted, so any divergence from a genuine TEE surfaces
|
||||
* directly as a differing field rather than having to be guessed.
|
||||
*/
|
||||
fun formatAttestationExtension(cert: X509Certificate): String? {
|
||||
val rawExtension = cert.getExtensionValue(ATTESTATION_OID.id) ?: return null
|
||||
return runCatching {
|
||||
val keyDescriptionDer = ASN1OctetString.getInstance(rawExtension).octets
|
||||
formatKeyDescription(ASN1Sequence.getInstance(keyDescriptionDer))
|
||||
}
|
||||
.getOrElse { "<unparseable attestation extension: ${it.message}>" }
|
||||
}
|
||||
|
||||
/** Renders the identity fields of every certificate in a returned chain for the dossier. */
|
||||
fun formatCertChain(chain: List<Certificate>): String =
|
||||
chain
|
||||
.mapIndexed { index, cert ->
|
||||
val x509 = cert as? X509Certificate ?: return@mapIndexed "[$index] <non-X509>"
|
||||
"[$index] subject=${x509.subjectX500Principal.name} " +
|
||||
"issuer=${x509.issuerX500Principal.name} " +
|
||||
"serial=${x509.serialNumber.toString(16)} " +
|
||||
"notBefore=${x509.notBefore} notAfter=${x509.notAfter}"
|
||||
}
|
||||
.joinToString(separator = " ; ")
|
||||
|
||||
private fun formatKeyDescription(seq: ASN1Sequence): String {
|
||||
val fields = seq.toArray()
|
||||
return "attestVer=${formatAsn1Primitive(fields[AttestationConstants.KEY_DESCRIPTION_ATTESTATION_VERSION_INDEX])} " +
|
||||
"attestSecLvl=${formatSecurityLevel(fields[AttestationConstants.KEY_DESCRIPTION_ATTESTATION_SECURITY_LEVEL_INDEX])} " +
|
||||
"kmVer=${formatAsn1Primitive(fields[AttestationConstants.KEY_DESCRIPTION_KEYMINT_VERSION_INDEX])} " +
|
||||
"kmSecLvl=${formatSecurityLevel(fields[AttestationConstants.KEY_DESCRIPTION_KEYMINT_SECURITY_LEVEL_INDEX])} " +
|
||||
"challenge=${formatAsn1Primitive(fields[AttestationConstants.KEY_DESCRIPTION_ATTESTATION_CHALLENGE_INDEX])} " +
|
||||
"uniqueId=${formatAsn1Primitive(fields[AttestationConstants.KEY_DESCRIPTION_UNIQUE_ID_INDEX])} " +
|
||||
"sw=${formatAuthorizationList(fields[AttestationConstants.KEY_DESCRIPTION_SOFTWARE_ENFORCED_INDEX])} " +
|
||||
"tee=${formatAuthorizationList(fields[AttestationConstants.KEY_DESCRIPTION_TEE_ENFORCED_INDEX])}"
|
||||
}
|
||||
|
||||
private fun formatSecurityLevel(obj: ASN1Encodable): String {
|
||||
val level = (obj.toASN1Primitive() as? ASN1Enumerated)?.value?.toInt()
|
||||
val name =
|
||||
when (level) {
|
||||
0 -> "Software"
|
||||
1 -> "TEE"
|
||||
2 -> "StrongBox"
|
||||
else -> "?"
|
||||
}
|
||||
return "$level($name)"
|
||||
}
|
||||
|
||||
private fun formatAuthorizationList(obj: ASN1Encodable): String {
|
||||
val seq = obj.toASN1Primitive() as? ASN1Sequence ?: return formatAsn1Primitive(obj)
|
||||
return seq
|
||||
.map { element ->
|
||||
val tagged = element as? ASN1TaggedObject ?: return@map formatAsn1Primitive(element)
|
||||
val name = attestTagNames[tagged.tagNo] ?: "TAG"
|
||||
val value =
|
||||
if (tagged.tagNo == AttestationConstants.TAG_ROOT_OF_TRUST)
|
||||
formatRootOfTrust(tagged.baseObject)
|
||||
else formatAsn1Primitive(tagged.baseObject)
|
||||
"${tagged.tagNo}($name)=$value"
|
||||
}
|
||||
.joinToString(prefix = "[", postfix = "]", separator = ", ")
|
||||
}
|
||||
|
||||
/**
|
||||
* Decodes the Root of Trust sub-sequence explicitly — it is the field a detector most often uses
|
||||
* to unmask a simulated TEE (a random verifiedBootKey, an unexpected verifiedBootState, or a
|
||||
* deviceLocked that disagrees with the bootloader all live here).
|
||||
*/
|
||||
private fun formatRootOfTrust(obj: ASN1Encodable): String {
|
||||
val fields = (obj.toASN1Primitive() as? ASN1Sequence)?.toArray() ?: return formatAsn1Primitive(obj)
|
||||
val state = fields.getOrNull(AttestationConstants.ROOT_OF_TRUST_VERIFIED_BOOT_STATE_INDEX)
|
||||
val stateName =
|
||||
when ((state?.toASN1Primitive() as? ASN1Enumerated)?.value?.toInt()) {
|
||||
0 -> "Verified"
|
||||
1 -> "SelfSigned"
|
||||
2 -> "Unverified"
|
||||
3 -> "Failed"
|
||||
else -> "?"
|
||||
}
|
||||
return "[bootKey=${formatAsn1Primitive(fields.getOrNull(AttestationConstants.ROOT_OF_TRUST_VERIFIED_BOOT_KEY_INDEX))}, " +
|
||||
"deviceLocked=${formatAsn1Primitive(fields.getOrNull(AttestationConstants.ROOT_OF_TRUST_DEVICE_LOCKED_INDEX))}, " +
|
||||
"verifiedBootState=${formatAsn1Primitive(state)}($stateName), " +
|
||||
"bootHash=${formatAsn1Primitive(fields.getOrNull(AttestationConstants.ROOT_OF_TRUST_VERIFIED_BOOT_HASH_INDEX))}]"
|
||||
}
|
||||
|
||||
// Function to check if a given ASN1Sequence contains the Root of Trust tag.
|
||||
private fun sequenceContainsRootOfTrust(seq: ASN1Encodable): Boolean {
|
||||
if (seq !is ASN1Sequence) return false
|
||||
|
||||
@@ -224,7 +224,11 @@ abstract class BinderInterceptor : Binder() {
|
||||
}
|
||||
}
|
||||
|
||||
/** Helper function for consistent logging of intercepted transactions. */
|
||||
/**
|
||||
* Logs an intercepted transaction. For a targeted UID every transaction — whether we intercept
|
||||
* or merely observe it — is recorded on that UID's own diagnostic plane, so its keystore
|
||||
* timeline reads cleanly end to end. Untargeted UIDs get a single terse, rate-limited line.
|
||||
*/
|
||||
protected fun logTransaction(
|
||||
txId: Long,
|
||||
methodName: String,
|
||||
@@ -232,15 +236,14 @@ abstract class BinderInterceptor : Binder() {
|
||||
callingPid: Int,
|
||||
skipPost: Boolean = false,
|
||||
) {
|
||||
val isIntercepting = !skipPost && !ConfigurationManager.shouldSkipUid(callingUid)
|
||||
val action = if (isIntercepting) "Intercept" else "Observe"
|
||||
val packages = ConfigurationManager.getPackagesForUid(callingUid).joinToString()
|
||||
val message =
|
||||
"[TX_ID: $txId] $action $methodName for packages=[$packages] (uid=$callingUid, pid=$callingPid)"
|
||||
if (isIntercepting) {
|
||||
SystemLogger.debug(message)
|
||||
} else {
|
||||
SystemLogger.verbose(message)
|
||||
if (SystemLogger.isUidLogged(callingUid)) {
|
||||
val action = if (skipPost) "observe" else "intercept"
|
||||
SystemLogger.uidLog(callingUid, txId, "tx", "$methodName action=$action pid=$callingPid")
|
||||
return
|
||||
}
|
||||
SystemLogger.verbose {
|
||||
val packages = ConfigurationManager.getPackagesForUid(callingUid).joinToString()
|
||||
"[TX_ID: $txId] Observe $methodName for packages=[$packages] (uid=$callingUid, pid=$callingPid)"
|
||||
}
|
||||
}
|
||||
|
||||
|
||||
+6
-1
@@ -18,6 +18,7 @@ import org.matrix.TEESimulator.attestation.KeyMintAttestation
|
||||
import org.matrix.TEESimulator.config.ConfigurationManager
|
||||
import org.matrix.TEESimulator.interception.keystore.shim.GeneratedKeyPersistence
|
||||
import org.matrix.TEESimulator.interception.keystore.shim.KeyMintSecurityLevelInterceptor
|
||||
import org.matrix.TEESimulator.logging.AttestationDossier
|
||||
import org.matrix.TEESimulator.logging.KeyMintParameterLogger
|
||||
import org.matrix.TEESimulator.logging.SystemLogger
|
||||
import org.matrix.TEESimulator.pki.CertificateGenerator
|
||||
@@ -348,7 +349,7 @@ object Keystore2Interceptor : AbstractKeystoreInterceptor() {
|
||||
|
||||
SystemLogger.info("[TX_ID: $txId] Found generated response for ${descriptor.alias}:")
|
||||
response.metadata?.authorizations?.forEach {
|
||||
KeyMintParameterLogger.logParameter(it.keyParameter)
|
||||
KeyMintParameterLogger.logParameter(callingUid, txId, it.keyParameter)
|
||||
}
|
||||
return InterceptorUtils.createTypedObjectReply(response)
|
||||
} else if (code == GRANT_TRANSACTION) {
|
||||
@@ -653,6 +654,10 @@ object Keystore2Interceptor : AbstractKeystoreInterceptor() {
|
||||
callingUid,
|
||||
)
|
||||
|
||||
// PATCH decode point: the patched chain actually served back to the app on
|
||||
// getKeyEntry — the ground truth a patch-mode detector reads.
|
||||
AttestationDossier.log(callingUid, txId, "PATCH", finalChain.asList())
|
||||
|
||||
return InterceptorUtils.createTypedObjectReply(response)
|
||||
}
|
||||
.onFailure {
|
||||
|
||||
+28
-11
@@ -34,6 +34,7 @@ import org.matrix.TEESimulator.interception.core.BinderInterceptor
|
||||
import org.matrix.TEESimulator.interception.keystore.InterceptorUtils
|
||||
import org.matrix.TEESimulator.interception.keystore.KeyIdentifier
|
||||
import org.matrix.TEESimulator.interception.keystore.Keystore2Interceptor
|
||||
import org.matrix.TEESimulator.logging.AttestationDossier
|
||||
import org.matrix.TEESimulator.logging.SystemLogger
|
||||
import org.matrix.TEESimulator.pki.CertGenConfig
|
||||
import org.matrix.TEESimulator.pki.CertificateGenerator
|
||||
@@ -274,6 +275,9 @@ class KeyMintSecurityLevelInterceptor(
|
||||
metadata.authorizations =
|
||||
InterceptorUtils.patchAuthorizations(metadata.authorizations, callingUid)
|
||||
|
||||
// PATCH decode point: the chain we rewrote onto a real TEE generateKey reply.
|
||||
AttestationDossier.log(callingUid, txId, "PATCH", newChain.asList())
|
||||
|
||||
cleanupKeyData(keyId)
|
||||
patchedChains[keyId] = newChain
|
||||
teeResponses[keyId] =
|
||||
@@ -556,14 +560,12 @@ class KeyMintSecurityLevelInterceptor(
|
||||
it.tag == Tag.ATTESTATION_ID_SECOND_IMEI
|
||||
}
|
||||
|
||||
// Debug-only probe trail: one greppable line per generateKey carrying the resolving
|
||||
// package and the outcome. Release builds short-circuit before any string is built,
|
||||
// so this is silent and artifact-free in production.
|
||||
// One `dispatch` record per generateKey on the targeted UID's diagnostic plane,
|
||||
// carrying the resolved outcome and the request shape that drove it. Scoped to
|
||||
// targeted UIDs, so the SKIP flood from every other app never reaches the plane;
|
||||
// release builds short-circuit before any string is built.
|
||||
fun logProbe(outcome: String) {
|
||||
if (!SystemLogger.isDebugBuild) return
|
||||
val pkg =
|
||||
ConfigurationManager.getPackagesForUid(callingUid).firstOrNull()
|
||||
?: "uid:$callingUid"
|
||||
if (!SystemLogger.isUidLogged(callingUid)) return
|
||||
val tags =
|
||||
buildList {
|
||||
if (parsedParams.attestationChallenge != null) add("challenge")
|
||||
@@ -579,10 +581,13 @@ class KeyMintSecurityLevelInterceptor(
|
||||
if (params.any { it.tag == Tag.INCLUDE_UNIQUE_ID }) add("unique_id")
|
||||
}
|
||||
.joinToString(",")
|
||||
SystemLogger.debug(
|
||||
"[probe] tx=$txId uid=$callingUid pkg=$pkg alias=${keyDescriptor.alias} " +
|
||||
SystemLogger.uidLog(
|
||||
callingUid,
|
||||
txId,
|
||||
"dispatch",
|
||||
"outcome=$outcome alias=${keyDescriptor.alias} " +
|
||||
"algo=${parsedParams.algorithm} sb=${securityLevel == SecurityLevel.STRONGBOX} " +
|
||||
"tags=[$tags] -> $outcome"
|
||||
"tags=[$tags]",
|
||||
)
|
||||
}
|
||||
|
||||
@@ -711,6 +716,7 @@ class KeyMintSecurityLevelInterceptor(
|
||||
forceGenerate -> {
|
||||
logProbe("FORGE")
|
||||
doSoftwareKeyGen(
|
||||
txId,
|
||||
callingUid,
|
||||
keyDescriptor,
|
||||
attestationKey,
|
||||
@@ -737,6 +743,7 @@ class KeyMintSecurityLevelInterceptor(
|
||||
}
|
||||
|
||||
private fun doSoftwareKeyGen(
|
||||
txId: Long,
|
||||
callingUid: Int,
|
||||
keyDescriptor: KeyDescriptor,
|
||||
attestationKey: KeyDescriptor?,
|
||||
@@ -851,9 +858,12 @@ class KeyMintSecurityLevelInterceptor(
|
||||
return InterceptorUtils.createTypedObjectReply(metadata, diagnosticTag = "gen-mode-sym")
|
||||
}
|
||||
|
||||
var forgePath = "FORGE-bouncycastle"
|
||||
val keyData =
|
||||
if (NativeCertGen.isAvailable && attestationKey == null) {
|
||||
generateAttestedKeyPairNative(callingUid, parsedParams)
|
||||
generateAttestedKeyPairNative(callingUid, parsedParams)?.also {
|
||||
forgePath = "FORGE-rust"
|
||||
}
|
||||
?: CertificateGenerator.generateAttestedKeyPair(
|
||||
callingUid,
|
||||
keyDescriptor.alias,
|
||||
@@ -871,6 +881,11 @@ class KeyMintSecurityLevelInterceptor(
|
||||
)
|
||||
} ?: throw Exception("Both native and BouncyCastle cert gen failed.")
|
||||
|
||||
// FORGE decode point: dump the dossier of the chain we just forged, tagged with the forger
|
||||
// that produced it. uid + txId are both in scope here, so this is the cheapest place to
|
||||
// capture ground truth for a generate-mode app.
|
||||
AttestationDossier.log(callingUid, txId, forgePath, keyData.second)
|
||||
|
||||
val response =
|
||||
buildKeyEntryResponse(callingUid, keyData.second, parsedParams, keyDescriptor)
|
||||
generatedKeys[keyId] =
|
||||
@@ -1015,6 +1030,8 @@ class KeyMintSecurityLevelInterceptor(
|
||||
callerNonce = params.callerNonce == true,
|
||||
unlockedDeviceRequired = params.unlockedDeviceRequired == true,
|
||||
noAuthRequired = params.noAuthRequired != false,
|
||||
uid = callingUid,
|
||||
debugLogging = SystemLogger.isDebugBuild,
|
||||
)
|
||||
|
||||
val resultBytes = NativeCertGen.generateAttestedKeyPair(config) ?: return null
|
||||
|
||||
@@ -0,0 +1,33 @@
|
||||
package org.matrix.TEESimulator.logging
|
||||
|
||||
import java.security.cert.Certificate
|
||||
import java.security.cert.X509Certificate
|
||||
import org.matrix.TEESimulator.attestation.AttestationPatcher
|
||||
import org.matrix.TEESimulator.config.ConfigurationManager
|
||||
import org.matrix.TEESimulator.util.AndroidDeviceUtils
|
||||
|
||||
/**
|
||||
* Assembles the per-UID "attestation dossier": for a targeted app, the full decoded attestation we
|
||||
* actually hand it, the identity of every certificate in the returned chain, and the source of each
|
||||
* device value that fed that attestation. Emitting all three where a chain is produced turns "the
|
||||
* app rejects us" into a field-by-field record that can be diffed against a genuine TEE.
|
||||
*/
|
||||
object AttestationDossier {
|
||||
|
||||
/**
|
||||
* Records the dossier for [chain] under [uid], tagged with the [path] that produced it
|
||||
* (`FORGE-rust`, `FORGE-bouncycastle`, or `PATCH`). No-op for untargeted UIDs and release
|
||||
* builds; the expensive decoding is skipped entirely when the UID is out of scope.
|
||||
*/
|
||||
fun log(uid: Int, txId: Long, path: String, chain: List<Certificate>) {
|
||||
if (!SystemLogger.isUidLogged(uid)) return
|
||||
val leaf = chain.firstOrNull() as? X509Certificate
|
||||
val extension =
|
||||
leaf?.let { AttestationPatcher.formatAttestationExtension(it) }
|
||||
?: "<no attestation extension>"
|
||||
SystemLogger.uidLog(uid, txId, "attest", "path=$path depth=${chain.size} $extension")
|
||||
SystemLogger.uidLog(uid, txId, "keybox", "file=${ConfigurationManager.getKeyboxFileForUid(uid)}")
|
||||
SystemLogger.uidLog(uid, txId, "chain", AttestationPatcher.formatCertChain(chain))
|
||||
SystemLogger.uidLog(uid, txId, "props", AndroidDeviceUtils.describeSources(uid))
|
||||
}
|
||||
}
|
||||
@@ -69,12 +69,23 @@ object KeyMintParameterLogger {
|
||||
.associate { field -> (field.get(null) as Int) to field.name }
|
||||
}
|
||||
|
||||
/**
|
||||
* Logs a single KeyParameter in a formatted, readable way.
|
||||
*
|
||||
* @param param The KeyParameter to log.
|
||||
*/
|
||||
/** Logs a single KeyParameter to the shared debug stream (used for un-scoped param dumps). */
|
||||
fun logParameter(param: KeyParameter) {
|
||||
SystemLogger.debug("KeyParam: ${describe(param)}")
|
||||
}
|
||||
|
||||
/** Logs a single KeyParameter onto a targeted UID's diagnostic plane as a `param` record. */
|
||||
fun logParameter(uid: Int, txId: Long, param: KeyParameter) {
|
||||
SystemLogger.uidLog(uid, txId, "param", describe(param))
|
||||
}
|
||||
|
||||
/**
|
||||
* Formats a single KeyParameter into a readable `tag | Value` string. Shared by both
|
||||
* [logParameter] overloads so the two logging planes render parameters identically.
|
||||
*
|
||||
* @param param The KeyParameter to format.
|
||||
*/
|
||||
private fun describe(param: KeyParameter): String {
|
||||
val tagName = tagNames[param.tag] ?: "UNKNOWN_TAG"
|
||||
val value = param.value
|
||||
val formattedValue: String =
|
||||
@@ -110,7 +121,7 @@ object KeyMintParameterLogger {
|
||||
else -> "<raw>"
|
||||
} ?: "Unknown Value"
|
||||
|
||||
SystemLogger.debug("KeyParam: %-25s | Value: %s".format(tagName, formattedValue))
|
||||
return "%-25s | Value: %s".format(tagName, formattedValue)
|
||||
}
|
||||
|
||||
private fun ByteArray.toReadableString(): String {
|
||||
|
||||
@@ -1,9 +1,17 @@
|
||||
package org.matrix.TEESimulator.logging
|
||||
|
||||
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.util.concurrent.ConcurrentHashMap
|
||||
import java.util.concurrent.atomic.AtomicInteger
|
||||
import java.util.concurrent.atomic.AtomicLong
|
||||
import org.matrix.TEESimulator.BuildConfig
|
||||
import org.matrix.TEESimulator.config.ConfigurationManager
|
||||
|
||||
/**
|
||||
* A centralized logging utility for the TEESimulator application. This object provides a consistent
|
||||
@@ -118,4 +126,97 @@ object SystemLogger {
|
||||
if (!isDebugBuild) return
|
||||
Log.w(TAG, message())
|
||||
}
|
||||
|
||||
// --- UID-keyed diagnostic plane (debug builds only) -------------------------------------
|
||||
|
||||
/**
|
||||
* True when [uid] should receive deep, per-UID diagnostic logging: a debug build AND the UID is
|
||||
* targeted in `target.txt`. This is the single scope gate for the diagnostic plane; it reuses
|
||||
* the existing activation set, so no new configuration surface is introduced.
|
||||
*/
|
||||
fun isUidLogged(uid: Int): Boolean = isDebugBuild && !ConfigurationManager.shouldSkipUid(uid)
|
||||
|
||||
/** Resolves a UID to its primary package name for log labelling, falling back to `uid:N`. */
|
||||
private fun label(uid: Int): String =
|
||||
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.
|
||||
*/
|
||||
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) }
|
||||
}
|
||||
|
||||
/** Lazy [uidLog]: [detail] is only built for targeted UIDs in debug builds. */
|
||||
inline fun uidLog(uid: Int, txId: Long?, event: String, detail: () -> String) {
|
||||
if (!isUidLogged(uid)) return
|
||||
uidLog(uid, txId, event, detail())
|
||||
}
|
||||
|
||||
private val uidLogDir = File(ConfigurationManager.CONFIG_PATH, "logs")
|
||||
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) }
|
||||
|
||||
/**
|
||||
* 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.
|
||||
*/
|
||||
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 var writer: BufferedWriter? = null
|
||||
private var size = 0L
|
||||
|
||||
@Synchronized
|
||||
fun append(message: String) {
|
||||
runCatching {
|
||||
val out = writer ?: open()
|
||||
val line = "${clock.format(Date())} $message\n"
|
||||
out.write(line)
|
||||
out.flush()
|
||||
size += line.length
|
||||
if (size >= UID_LOG_MAX_BYTES) rotate()
|
||||
}
|
||||
}
|
||||
|
||||
private fun open(): BufferedWriter {
|
||||
logDir.mkdirs()
|
||||
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
|
||||
}
|
||||
|
||||
private fun rotate() {
|
||||
runCatching {
|
||||
writer?.flush()
|
||||
writer?.close()
|
||||
}
|
||||
writer = null
|
||||
runCatching {
|
||||
if (rotated.exists()) rotated.delete()
|
||||
primary.renameTo(rotated)
|
||||
}
|
||||
size = 0L
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
@@ -52,6 +52,10 @@ data class CertGenConfig(
|
||||
val callerNonce: Boolean = false,
|
||||
val unlockedDeviceRequired: Boolean = false,
|
||||
val noAuthRequired: Boolean = true,
|
||||
// Diagnostic plane: the calling app UID keys the native log lines, and debugLogging mirrors the
|
||||
// APK debug variant so the native extension dump is silent in release.
|
||||
val uid: Int,
|
||||
val debugLogging: Boolean,
|
||||
)
|
||||
|
||||
object NativeCertGen {
|
||||
|
||||
@@ -43,6 +43,7 @@ object AndroidDeviceUtils {
|
||||
DeviceAttestationService.CachedAttestationData?.verifiedBootKey
|
||||
},
|
||||
expectedSize = 32,
|
||||
recordSource = { bootKeySource = it },
|
||||
)
|
||||
}
|
||||
|
||||
@@ -60,9 +61,16 @@ object AndroidDeviceUtils {
|
||||
DeviceAttestationService.CachedAttestationData?.verifiedBootHash
|
||||
},
|
||||
expectedSize = 32,
|
||||
recordSource = { bootHashSource = it },
|
||||
)
|
||||
}
|
||||
|
||||
// Records which fallback tier supplied bootKey/bootHash so the diagnostic dossier can flag a
|
||||
// random-fallback value — a real verifiedBootKey that resolves to random bytes is a textbook
|
||||
// simulated-TEE tell. Populated by initializeBootProperty on first access.
|
||||
@Volatile private var bootKeySource: String = "uninitialized"
|
||||
@Volatile private var bootHashSource: String = "uninitialized"
|
||||
|
||||
/**
|
||||
* Public function to explicitly trigger the initialization of the boot key and hash. Accessing
|
||||
* these properties here ensures they are set up before they might be needed elsewhere.
|
||||
@@ -89,9 +97,11 @@ object AndroidDeviceUtils {
|
||||
propertyName: String,
|
||||
attestationValueProvider: () -> ByteArray?,
|
||||
expectedSize: Int,
|
||||
recordSource: (String) -> Unit,
|
||||
): ByteArray {
|
||||
getProperty(propertyName, expectedSize)?.let {
|
||||
SystemLogger.debug("Using $propertyName from system property: ${it.toHex()}")
|
||||
recordSource("system-prop")
|
||||
persistToFile(propertyName, it)
|
||||
return it
|
||||
}
|
||||
@@ -99,6 +109,7 @@ object AndroidDeviceUtils {
|
||||
try {
|
||||
attestationValueProvider()?.let {
|
||||
SystemLogger.debug("Using $propertyName from TEE attestation: ${it.toHex()}")
|
||||
recordSource("tee-attestation")
|
||||
setProperty(propertyName, it)
|
||||
persistToFile(propertyName, it)
|
||||
return it
|
||||
@@ -109,12 +120,14 @@ object AndroidDeviceUtils {
|
||||
|
||||
readFromFile(propertyName, expectedSize)?.let {
|
||||
SystemLogger.debug("Using $propertyName from persistent file: ${it.toHex()}")
|
||||
recordSource("persistent-file")
|
||||
setProperty(propertyName, it)
|
||||
return it
|
||||
}
|
||||
|
||||
return generateRandomBytes(expectedSize).also {
|
||||
SystemLogger.debug("Using randomly generated $propertyName: ${it.toHex()}")
|
||||
recordSource("random-fallback")
|
||||
setProperty(propertyName, it)
|
||||
persistToFile(propertyName, it)
|
||||
}
|
||||
@@ -230,6 +243,23 @@ object AndroidDeviceUtils {
|
||||
return custom ?: getRealDevicePatchLevelInt("boot", isLong = true)
|
||||
}
|
||||
|
||||
/**
|
||||
* Summarises, for a targeted [uid], the device values that feed attestation and where each came
|
||||
* from. This is what exposes attested-versus-live mismatches: a random-fallback verifiedBootKey,
|
||||
* a patch level overridden away from the live prop, or an OS version pulled from a stale cache.
|
||||
*/
|
||||
fun describeSources(uid: Int): String {
|
||||
val customPatchLevel = ConfigurationManager.getPatchLevelForUid(uid) != null
|
||||
val osVersionSource =
|
||||
if (DeviceAttestationService.CachedAttestationData?.osVersion != null) "cache" else "map"
|
||||
return "osVersion=$osVersion(src=$osVersionSource) " +
|
||||
"osPatch=${getPatchLevel(uid)} vendorPatch=${getVendorPatchLevelLong(uid)} " +
|
||||
"bootPatch=${getBootPatchLevelLong(uid)} customPatchLevel=$customPatchLevel " +
|
||||
"bootKey=${bootKey.toHex()}(src=$bootKeySource) " +
|
||||
"bootHash=${bootHash.toHex()}(src=$bootHashSource) " +
|
||||
"teeCacheData=${DeviceAttestationService.CachedAttestationData != null}"
|
||||
}
|
||||
|
||||
/**
|
||||
* Retrieves the definitive device patch level integer for a given component. This function
|
||||
* encapsulates the entire fallback chain and guarantees a non-null return.
|
||||
|
||||
Reference in New Issue
Block a user