Improve SAF performance and defer custom filename template processing to the end of the call

app/src/main/java/com/chiller3/bcr/DocumentFileExtensions.kt

@@ -0,0 +1,100 @@
+package com.chiller3.bcr
+
+import android.content.Context
+import android.net.Uri
+import android.provider.DocumentsContract
+import android.util.Log
+import androidx.documentfile.provider.DocumentFile
+
+private const val TAG = "DocumentFileExtensions"
+
+private fun DocumentFile.iterChildrenWithColumns(extraColumns: Array<String>) = iterator {
+    if (!DocumentsContract.isTreeUri(uri)) {
+        throw IllegalArgumentException("Not a tree URI")
+    }
+
+    val file = this@iterChildrenWithColumns
+
+    // These reflection calls access private fields, but everything is part of the
+    // androidx.documentfile:documentfile dependency and we control the version of that.
+
+    val context = file.javaClass.getDeclaredField("mContext").apply {
+        isAccessible = true
+    }.get(file) as Context
+
+    val constructor = file.javaClass.getDeclaredConstructor(
+        DocumentFile::class.java,
+        Context::class.java,
+        Uri::class.java,
+    ).apply {
+        isAccessible = true
+    }
+
+    context.contentResolver.query(
+        DocumentsContract.buildChildDocumentsUriUsingTree(
+            uri,
+            DocumentsContract.getDocumentId(uri),
+        ),
+        arrayOf(DocumentsContract.Document.COLUMN_DOCUMENT_ID) + extraColumns,
+        null, null, null,
+    )?.use {
+        while (it.moveToNext()) {
+            val child: DocumentFile = constructor.newInstance(
+                file,
+                context,
+                DocumentsContract.buildDocumentUriUsingTree(uri, it.getString(0)),
+            )
+
+            yield(Pair(child, it))
+        }
+    }
+}
+
+/**
+ * List files along with their display names, but faster for tree URIs.
+ *
+ * For non-tree URIs, this is equivalent to calling [DocumentFile.listFiles], followed by
+ * [DocumentFile.getName] for each entry. For tree URIs, this only performs a single query to the
+ * document provider.
+ */
+fun DocumentFile.listFilesWithNames(): List<Pair<DocumentFile, String?>> {
+    if (!DocumentsContract.isTreeUri(uri)) {
+        return listFiles().map { Pair(it, it.name) }
+    }
+
+    try {
+        return iterChildrenWithColumns(arrayOf(DocumentsContract.Document.COLUMN_DISPLAY_NAME))
+            .asSequence()
+            .map { Pair(it.first, it.second.getString(1)) }
+            .toList()
+    } catch (e: Exception) {
+        Log.w(TAG, "Failed to query tree URI", e)
+    }
+
+    return listOf()
+}
+
+/**
+ * Like [DocumentFile.findFile], but faster for tree URIs.
+ *
+ * [DocumentFile.findFile] performs a query for the document ID list and then performs separate
+ * queries for each document to get the name. This is extremely slow on some devices and is
+ * unnecessary because [DocumentsContract.Document.COLUMN_DOCUMENT_ID] and
+ * [DocumentsContract.Document.COLUMN_DISPLAY_NAME] can be queried at the same time.
+ */
+fun DocumentFile.findFileFast(displayName: String): DocumentFile? {
+    if (!DocumentsContract.isTreeUri(uri)) {
+        return findFile(displayName)
+    }
+
+    try {
+        return iterChildrenWithColumns(arrayOf(DocumentsContract.Document.COLUMN_DISPLAY_NAME))
+            .asSequence()
+            .find { it.second.getString(1) == displayName }
+            ?.first
+    } catch (e: Exception) {
+        Log.w(TAG, "Failed to query tree URI", e)
+    }
+
+    return null
+}

app/src/main/java/com/chiller3/bcr/FilenameTemplate.kt

@@ -101,27 +101,33 @@ class FilenameTemplate private constructor(props: Properties) {
                 }
             }.isNotEmpty()
 
-        fun load(context: Context): FilenameTemplate {
+        fun load(context: Context, allowCustom: Boolean): FilenameTemplate {
             val props = Properties()
 
-            val prefs = Preferences(context)
-            val outputDir = prefs.outputDir?.let {
-                // Only returns null on API <21
-                DocumentFile.fromTreeUri(context, it)!!
-            } ?: DocumentFile.fromFile(prefs.defaultOutputDir)
-
-            val templateFile = outputDir.findFile("bcr.properties")
-            if (templateFile != null) {
-                try {
-                    Log.d(TAG, "Loading custom filename template: ${templateFile.uri}")
-
-                    context.contentResolver.openInputStream(templateFile.uri)?.use {
-                        props.load(it)
-                        return FilenameTemplate(props)
+            if (allowCustom) {
+                val prefs = Preferences(context)
+                val outputDir = prefs.outputDir?.let {
+                    // Only returns null on API <21
+                    DocumentFile.fromTreeUri(context, it)!!
+                } ?: DocumentFile.fromFile(prefs.defaultOutputDir)
+
+                Log.d(TAG, "Looking for custom filename template in: ${outputDir.uri}")
+
+                val templateFile = outputDir.findFileFast("bcr.properties")
+                if (templateFile != null) {
+                    try {
+                        Log.d(TAG, "Loading custom filename template: ${templateFile.uri}")
+
+                        context.contentResolver.openInputStream(templateFile.uri)?.use {
+                            props.load(it)
+                            return FilenameTemplate(props)
+                        }
+                    } catch (e: Exception) {
+                        Log.w(TAG, "Failed to load custom filename template", e)
                     }
-                } catch (e: Exception) {
-                    Log.w(TAG, "Failed to load custom filename template", e)
                 }
+            } else {
+                Log.d(TAG, "Inhibited loading of custom filename template")
             }
 
             Log.d(TAG, "Loading default filename template")

app/src/main/java/com/chiller3/bcr/RecorderThread.kt

@@ -77,6 +77,7 @@ class RecorderThread(
     // Filename
     private val filenameLock = Object()
     private var pendingCallDetails: Call.Details? = null
+    private lateinit var lastCallDetails: Call.Details
     private lateinit var filenameTemplate: FilenameTemplate
     private lateinit var filename: String
     private val redactions = HashMap<String, String>()
@@ -103,6 +104,7 @@ class RecorderThread(
     private val sampleRate = SampleRate.fromPreferences(prefs)
 
     // Logging
+    private lateinit var logcatFilename: String
     private lateinit var logcatFile: DocumentFile
     private lateinit var logcatProcess: Process
 
@@ -130,6 +132,8 @@ class RecorderThread(
                 return
             }
 
+            lastCallDetails = details
+
             redactions.clear()
 
             filename = filenameTemplate.evaluate {
@@ -228,7 +232,10 @@ class RecorderThread(
         var resultUri: Uri? = null
 
         synchronized(filenameLock) {
-            filenameTemplate = FilenameTemplate.load(context)
+            // We initially do not allow custom filename templates because SAF is extraordinarily
+            // slow on some devices. Even with the our custom findFileFast() implementation, simply
+            // checking for the existence of the template may take >500ms.
+            filenameTemplate = FilenameTemplate.load(context, false)
 
             onCallDetailsChanged(pendingCallDetails!!)
             pendingCallDetails = null
@@ -252,7 +259,12 @@ class RecorderThread(
                         Os.fsync(it.fileDescriptor)
                     }
                 } finally {
-                    val finalFilename = synchronized(filenameLock) { filename }
+                    val finalFilename = synchronized(filenameLock) {
+                        filenameTemplate = FilenameTemplate.load(context, true)
+
+                        onCallDetailsChanged(lastCallDetails)
+                        filename
+                    }
                     if (finalFilename != initialFilename) {
                         Log.i(tag, "Renaming ${redactor.redact(initialFilename)} to ${redactor.redact(finalFilename)}")
 
@@ -331,11 +343,12 @@ class RecorderThread(
             return
         }
 
-        Log.d(tag, "Starting log file (${BuildConfig.VERSION_NAME})")
+        assert(!this::logcatProcess.isInitialized) { "logcat already started" }
 
-        val logFilename = synchronized(filenameLock) { "${filename}.log" }
+        Log.d(tag, "Starting log file (${BuildConfig.VERSION_NAME})")
 
-        logcatFile = dirUtils.createFileInDefaultDir(logFilename, "text/plain")
+        logcatFilename = synchronized(filenameLock) { "${filename}.log" }
+        logcatFile = dirUtils.createFileInDefaultDir(logcatFilename, "text/plain")
         logcatProcess = ProcessBuilder("logcat", "*:V")
             // This is better than -f because the logcat implementation calls fflush() when the
             // output stream is stdout. logcatFile is guaranteed to have file:// scheme because it's
@@ -350,6 +363,8 @@ class RecorderThread(
             return
         }
 
+        assert(this::logcatProcess.isInitialized) { "logcat not started" }
+
         try {
             try {
                 Log.d(tag, "Stopping log file")
@@ -363,6 +378,16 @@ class RecorderThread(
                 logcatProcess.waitFor()
             }
         } finally {
+            val finalLogcatFilename = synchronized(filenameLock) { "${filename}.log" }
+
+            if (finalLogcatFilename != logcatFilename) {
+                Log.i(tag, "Renaming ${redactor.redact(logcatFilename)} to ${redactor.redact(finalLogcatFilename)}")
+
+                if (!logcatFile.renameTo(finalLogcatFilename)) {
+                    Log.w(tag, "Failed to rename to final filename: ${redactor.redact(finalLogcatFilename)}")
+                }
+            }
+
             dirUtils.tryMoveToUserDir(logcatFile)
         }
     }
@@ -415,11 +440,13 @@ class RecorderThread(
         }
         Log.i(tag, "Retention period is $retention")
 
-        for (item in directory.listFiles()) {
-            val filename = item.name ?: continue
-            val redacted = redactTruncate(filename)
+        for ((item, name) in directory.listFilesWithNames()) {
+            if (name == null) {
+                continue
+            }
+            val redacted = redactTruncate(name)
 
-            val timestamp = timestampFromFilename(filename)
+            val timestamp = timestampFromFilename(name)
             if (timestamp == null) {
                 Log.w(tag, "Ignoring unrecognized filename: $redacted")
                 continue