diff --git a/app/build.gradle.kts b/app/build.gradle.kts index aca6b7ea30c..ee3a4c4a101 100644 --- a/app/build.gradle.kts +++ b/app/build.gradle.kts @@ -196,6 +196,8 @@ if (!project.hasProperty("skip.aboutlibraries")) { } dependencies { + implementation(libs.kermit.io) + implementation("com.wire.kalium:kalium-logic") implementation("com.wire.kalium:kalium-util") implementation("com.wire.kalium:kalium-cells") diff --git a/app/src/main/kotlin/com/wire/android/WireApplication.kt b/app/src/main/kotlin/com/wire/android/WireApplication.kt index e4051e24725..7f42e1aa49c 100644 --- a/app/src/main/kotlin/com/wire/android/WireApplication.kt +++ b/app/src/main/kotlin/com/wire/android/WireApplication.kt @@ -28,6 +28,7 @@ import android.util.Log import androidx.lifecycle.ProcessLifecycleOwner import androidx.work.Configuration import androidx.work.WorkManager +import co.touchlab.kermit.LogWriter import co.touchlab.kermit.platformLogWriter import com.wire.android.analytics.ObserveCurrentSessionAnalyticsUseCase import com.wire.android.datastore.GlobalDataStore @@ -351,7 +352,7 @@ class WireApplication : BaseApp() { ExternalLoggerManager.initDatadogLogger(applicationContext) val isLoggingEnabled = globalDataStore.value.isLoggingEnabled().firstOrNull() == true - val config = fullLoggerConfig(isLoggingEnabled) + val config = fullLoggerConfig(isLoggingEnabled, logFileWriter.value.logWriter) AppLogger.init(config) CoreLogger.init(config) @@ -467,13 +468,16 @@ class WireApplication : BaseApp() { listOf(platformLogWriter()) ) - fun fullLoggerConfig(isLoggingEnabled: Boolean) = if (isLoggingEnabled) { + fun fullLoggerConfig(isLoggingEnabled: Boolean, fileLogWriter: LogWriter? = null) = if (isLoggingEnabled) { KaliumLogger.Config( KaliumLogLevel.VERBOSE, - listOf(DataDogLogger, platformLogWriter()) + listOfNotNull(DataDogLogger, platformLogWriter(), fileLogWriter) ) } else { - minimalLoggerConfig() + KaliumLogger.Config( + KaliumLogLevel.WARN, + listOfNotNull(platformLogWriter(), fileLogWriter) + ) } enum class MemoryLevel(val level: Int) { diff --git a/app/src/main/kotlin/com/wire/android/ui/debug/LogManagementViewModel.kt b/app/src/main/kotlin/com/wire/android/ui/debug/LogManagementViewModel.kt index 15c14744e3b..569303a18cd 100644 --- a/app/src/main/kotlin/com/wire/android/ui/debug/LogManagementViewModel.kt +++ b/app/src/main/kotlin/com/wire/android/ui/debug/LogManagementViewModel.kt @@ -22,6 +22,7 @@ import androidx.compose.runtime.mutableStateOf import androidx.compose.runtime.setValue import androidx.lifecycle.ViewModel import androidx.lifecycle.viewModelScope +import com.wire.android.AppLogger import com.wire.android.datastore.GlobalDataStore import com.wire.android.util.logging.LogFileWriter import dev.zacsweers.metro.Inject @@ -54,16 +55,18 @@ class LogManagementViewModel @Inject constructor( globalDataStore.setLoggingEnabled(isEnabled) if (isEnabled) { logFileWriter.start() + AppLogger.setLogLevel(level = KaliumLogLevel.VERBOSE) CoreLogger.setLoggingLevel(level = KaliumLogLevel.VERBOSE) } else { logFileWriter.stop() + AppLogger.setLogLevel(level = KaliumLogLevel.WARN) CoreLogger.setLoggingLevel(level = KaliumLogLevel.DISABLED) } } } fun deleteLogs() { - logFileWriter.deleteAllLogFiles() + viewModelScope.launch { logFileWriter.deleteAllLogFiles() } } fun flushLogs(): Deferred { diff --git a/app/src/main/kotlin/com/wire/android/ui/debug/UserDebugViewModel.kt b/app/src/main/kotlin/com/wire/android/ui/debug/UserDebugViewModel.kt index 8f2023cbf90..fdb56e05cac 100644 --- a/app/src/main/kotlin/com/wire/android/ui/debug/UserDebugViewModel.kt +++ b/app/src/main/kotlin/com/wire/android/ui/debug/UserDebugViewModel.kt @@ -23,6 +23,7 @@ import androidx.compose.runtime.mutableStateOf import androidx.compose.runtime.setValue import androidx.lifecycle.ViewModel import androidx.lifecycle.viewModelScope +import com.wire.android.AppLogger import com.wire.android.datastore.GlobalDataStore import com.wire.android.di.CurrentAccount import com.wire.android.util.EMPTY @@ -83,7 +84,7 @@ class UserDebugViewModel @Inject constructor( } fun deleteLogs() { - logFileWriter.deleteAllLogFiles() + viewModelScope.launch { logFileWriter.deleteAllLogFiles() } } fun flushLogs(): Deferred { @@ -97,9 +98,11 @@ class UserDebugViewModel @Inject constructor( globalDataStore.setLoggingEnabled(isEnabled) if (isEnabled) { logFileWriter.start() + AppLogger.setLogLevel(level = KaliumLogLevel.VERBOSE) CoreLogger.setLoggingLevel(level = KaliumLogLevel.VERBOSE) } else { logFileWriter.stop() + AppLogger.setLogLevel(level = KaliumLogLevel.WARN) CoreLogger.setLoggingLevel(level = KaliumLogLevel.DISABLED) } } diff --git a/app/src/main/kotlin/com/wire/android/util/logging/LogFileWriter.kt b/app/src/main/kotlin/com/wire/android/util/logging/LogFileWriter.kt index 99af4188b8e..f329d609685 100644 --- a/app/src/main/kotlin/com/wire/android/util/logging/LogFileWriter.kt +++ b/app/src/main/kotlin/com/wire/android/util/logging/LogFileWriter.kt @@ -19,6 +19,7 @@ package com.wire.android.util.logging import android.content.Context +import co.touchlab.kermit.LogWriter import java.io.File /** @@ -27,6 +28,9 @@ import java.io.File */ interface LogFileWriter { + /** The Kermit sink that persists enabled diagnostics directly to files. */ + val logWriter: LogWriter + /** * The active logging file where logs are currently being written */ @@ -51,7 +55,7 @@ interface LogFileWriter { * Deletes all log files including active and compressed files * */ - fun deleteAllLogFiles() + suspend fun deleteAllLogFiles() companion object { fun logsDirectory(context: Context) = File(context.cacheDir, "logs") diff --git a/app/src/main/kotlin/com/wire/android/util/logging/LogFileWriterConfig.kt b/app/src/main/kotlin/com/wire/android/util/logging/LogFileWriterConfig.kt index b151aad56a3..3ac1e021677 100644 --- a/app/src/main/kotlin/com/wire/android/util/logging/LogFileWriterConfig.kt +++ b/app/src/main/kotlin/com/wire/android/util/logging/LogFileWriterConfig.kt @@ -19,20 +19,16 @@ package com.wire.android.util.logging data class LogFileWriterConfig( - val flushIntervalMs: Long = DEFAULT_FLUSH_INTERVAL_MS, - val maxBufferSize: Int = DEFAULT_MAX_BUFFER_SIZE, - val bufferSizeBytes: Int = DEFAULT_BUFFER_SIZE_BYTES, - val maxFileSize: Long = DEFAULT_MAX_FILE_SIZE_BYTES, + val rollOnSizeBytes: Long = DEFAULT_ROLL_ON_SIZE_BYTES, + val maxLogFiles: Int = DEFAULT_MAX_LOG_FILES, val flushTimeoutMs: Long = DEFAULT_FLUSH_TIMEOUT_MS, - val bufferLockTimeoutMs: Long = DEFAULT_BUFFER_LOCK_TIMEOUT_MS ) { companion object { - private const val DEFAULT_FLUSH_INTERVAL_MS = 5000L - private const val DEFAULT_MAX_BUFFER_SIZE = 100 - private const val DEFAULT_BUFFER_SIZE_BYTES = 64 * 1024 - private const val DEFAULT_MAX_FILE_SIZE_BYTES = 25 * 1024 * 1024L // 25MB + private const val DEFAULT_ROLL_ON_SIZE_BYTES = 25 * 1024 * 1024L // 25 MiB + + // RollingFileLogWriter counts the active file, so this retains ten rolled files. + private const val DEFAULT_MAX_LOG_FILES = 11 private const val DEFAULT_FLUSH_TIMEOUT_MS = 5000L // 5 seconds - private const val DEFAULT_BUFFER_LOCK_TIMEOUT_MS = 3000L // 3 seconds fun default() = LogFileWriterConfig() } diff --git a/app/src/main/kotlin/com/wire/android/util/logging/LogFileWriterImpl.kt b/app/src/main/kotlin/com/wire/android/util/logging/LogFileWriterImpl.kt index 410043a91c6..3613a3a2242 100644 --- a/app/src/main/kotlin/com/wire/android/util/logging/LogFileWriterImpl.kt +++ b/app/src/main/kotlin/com/wire/android/util/logging/LogFileWriterImpl.kt @@ -1,435 +1,189 @@ /* * Wire - * Copyright (C) 2025 Wire Swiss GmbH + * Copyright (C) 2026 Wire Swiss GmbH * * This program is free software: you can redistribute it and/or modify * it under the terms of the GNU General Public License as published by * the Free Software Foundation, either version 3 of the License, or * (at your option) any later version. - * - * This program is distributed in the hope that it will be useful, - * but WITHOUT ANY WARRANTY; without even the implied warranty of - * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the - * GNU General Public License for more details. - * - * You should have received a copy of the GNU General Public License - * along with this program. If not, see http://www.gnu.org/licenses/. */ - package com.wire.android.util.logging -import android.util.Log -import com.wire.android.appLogger -import kotlinx.coroutines.CoroutineScope +import co.touchlab.kermit.LogWriter +import co.touchlab.kermit.Severity +import co.touchlab.kermit.io.RollingFileLogWriter +import co.touchlab.kermit.io.RollingFileLogWriterConfig import kotlinx.coroutines.Dispatchers -import kotlinx.coroutines.Job -import kotlinx.coroutines.SupervisorJob -import kotlinx.coroutines.TimeoutCancellationException -import kotlinx.coroutines.cancelAndJoin import kotlinx.coroutines.delay -import kotlinx.coroutines.ensureActive -import kotlinx.coroutines.flow.Flow -import kotlinx.coroutines.flow.catch -import kotlinx.coroutines.flow.filter -import kotlinx.coroutines.flow.flow -import kotlinx.coroutines.flow.flowOn -import kotlinx.coroutines.flow.onEach -import kotlinx.coroutines.isActive -import kotlinx.coroutines.launch -import kotlinx.coroutines.sync.Mutex -import kotlinx.coroutines.sync.withLock import kotlinx.coroutines.withContext import kotlinx.coroutines.withTimeout -import java.io.BufferedWriter +import kotlinx.io.files.Path import java.io.File -import java.io.FileWriter import java.io.IOException -import java.io.PrintWriter -import java.text.SimpleDateFormat -import java.util.Date -import java.util.Locale +import java.util.UUID +import java.util.zip.GZIPInputStream import java.util.zip.GZIPOutputStream +import kotlin.time.Duration.Companion.milliseconds -@Suppress("TooGenericExceptionCaught", "TooManyFunctions") +/** Persists Wire diagnostics directly from Kermit instead of reading device logcat. */ class LogFileWriterImpl( private val logsDirectory: File, - private val config: LogFileWriterConfig = LogFileWriterConfig.default() + private val config: LogFileWriterConfig = LogFileWriterConfig.default(), ) : LogFileWriter { - private val logFileTimeFormat = SimpleDateFormat("yyyy-MM-dd_HH-mm-ss", Locale.US) - - override val activeLoggingFile = File(logsDirectory, ACTIVE_LOGGING_FILE_NAME) - - private val fileWriterCoroutineScope: CoroutineScope = CoroutineScope(SupervisorJob() + Dispatchers.IO) - private var writingJob: Job? = null - private var flushJob: Job? = null + override val activeLoggingFile = File(logsDirectory, "$LOG_FILE_NAME.log") - // Buffering system - private val logBuffer = mutableListOf() - private val bufferMutex = Mutex() - private var lastFlushTime = 0L - private var bufferedWriter: BufferedWriter? = null + private var rollingWriter: RollingFileLogWriter? = null + private val gatedWriter = GatedLogWriter { rollingWriter } - // Process management - private var logcatProcess: Process? = null + override val logWriter: LogWriter = gatedWriter - /** - * Initializes logging, waiting until the logger is actually initialized before returning. - * ```kotlin - * logFileWriter.start() - * logger.i("something") // Is guaranteed to be recorded in the log file - * ``` - */ - override suspend fun start() { - appLogger.i("KaliumFileWritter.start called") - val isWriting = writingJob?.isActive ?: false - if (isWriting) { - appLogger.d("KaliumFileWriter.init called but job was already active. Ignoring call") - return + override suspend fun start() = withContext(Dispatchers.IO) { + ensureLogDirectoryExists() + migrateLegacyLogs() + if (!activeLoggingFile.exists()) activeLoggingFile.createNewFile() + if (!activeLoggingFile.exists()) { + throw IOException("Unable to create log file: ${activeLoggingFile.absolutePath}") } - ensureLogDirectoryAndFileExistence() - cleanupOrphanedTempFiles() - val waitInitializationJob = Job() - - writingJob = fileWriterCoroutineScope.launch { - observeLogCatWritingToLoggingFile().catch { - appLogger.e("Write to file failed :$it", it) - }.onEach { - waitInitializationJob.complete() - }.filter { - it > config.maxFileSize - }.collect { - ensureActive() - // Flush buffer before compression - bufferMutex.withLock { - flushBuffer() - } - // Copy the file to a temp location with timestamped name, then compress the copy asynchronously - val compressedFileName = compressedFileName() - val tempFile = copyActiveLogFileToTemp(compressedFileName) - launch { - try { - compressFileAsync(tempFile, compressedFileName) - } finally { - tempFile.delete() - } - } - clearActiveLoggingFileContent() - deleteOldCompressedFiles() - } - } - - // Start periodic flush job - flushJob = fileWriterCoroutineScope.launch { - while (isActive) { - delay(config.flushIntervalMs) - try { - withTimeout(config.bufferLockTimeoutMs) { - bufferMutex.withLock { - if (logBuffer.isNotEmpty()) { - flushBuffer() - lastFlushTime = System.currentTimeMillis() - } - } - } - } catch (e: TimeoutCancellationException) { - appLogger.w("Periodic flush timed out, buffer may be locked by another operation", e) - } catch (e: Exception) { - appLogger.e("Error during periodic flush", e) - } - } + if (rollingWriter == null) { + rollingWriter = RollingFileLogWriter( + RollingFileLogWriterConfig( + logFileName = LOG_FILE_NAME, + logFilePath = Path(logsDirectory.absolutePath), + rollOnSize = config.rollOnSizeBytes, + maxLogFiles = config.maxLogFiles, + ) + ) } + gatedWriter.enable() + } - appLogger.i("KaliumFileWritter.start: Starting log collection.") - waitInitializationJob.join() + override suspend fun stop() { + gatedWriter.disable() } - /** - * Observes logcat text, writing to the [activeLoggingFile] as it reads. - * @return A Flow that tells the current length, in bytes, of the log file. - */ - private fun CoroutineScope.observeLogCatWritingToLoggingFile(): Flow = flow { - Log.i(LOG_TAG, "Starting logcat capture: clearing buffer") - logcatProcess = try { - Runtime.getRuntime().exec("logcat -c") - Log.i(LOG_TAG, "Starting logcat capture process") - Runtime.getRuntime().exec("logcat") - } catch (t: Throwable) { - Log.e(LOG_TAG, "Failed to start logcat capture", t) - null - } + override suspend fun forceFlush() { + gatedWriter.flushBarrier()?.let { marker -> waitForBarrier(marker) } + } - val reader = logcatProcess?.inputStream?.bufferedReader() + override suspend fun deleteAllLogFiles() { + val marker = gatedWriter.flushBarrier(disableAfterWrite = true) + marker?.let { flushMarker -> waitForBarrier(flushMarker) } - appLogger.i("Starting to write log files, grabbing from logcat") - while (isActive) { - val text = reader?.readLine() - if (!text.isNullOrBlank()) { - val fileSize = writeLineToFile(text) - emit(fileSize) - } + withContext(Dispatchers.IO) { + logsDirectory.listFiles() + ?.filter { ROLLED_LOG_FILE_REGEX.matches(it.name) } + ?.forEach(File::delete) + deleteLegacyLogFiles() + ensureLogDirectoryExists() + activeLoggingFile.outputStream().use { } } - reader?.close() - stopLogcatProcess() - }.flowOn(Dispatchers.IO) - private fun stopLogcatProcess() { - logcatProcess?.let { process -> - try { - process.destroy() - if (process.isAlive && android.os.Build.VERSION.SDK_INT >= android.os.Build.VERSION_CODES.O) { - process.destroyForcibly() - } - } catch (e: Exception) { - appLogger.e("Error stopping logcat process", e) - } - } - logcatProcess = null + if (marker != null) gatedWriter.enable() } - /** - * Stops processing logs and writing to files - */ - override suspend fun stop() { - appLogger.i("KaliumFileWritter.stop called; Stopping log collection.") - try { - // Stop logcat process first to prevent new logs - stopLogcatProcess() - // Cancel jobs with timeout to avoid hanging - writingJob?.let { job -> - try { - withTimeout(config.flushTimeoutMs) { - job.cancelAndJoin() - } - } catch (e: TimeoutCancellationException) { - appLogger.w("Writing job cancellation timed out, forcing cancellation") - job.cancel() - } - } - - flushJob?.let { job -> - try { - withTimeout(config.flushTimeoutMs) { - job.cancelAndJoin() - } - } catch (e: TimeoutCancellationException) { - appLogger.w("Flush job cancellation timed out, forcing cancellation") - job.cancel() - } - } - - // Flush any remaining buffered content with timeout - try { - withTimeout(config.flushTimeoutMs) { - bufferMutex.withLock { - flushBuffer() - } - } - } catch (e: TimeoutCancellationException) { - appLogger.w("Final buffer flush timed out, some logs may be lost") - } catch (e: Exception) { - appLogger.e("Error during final buffer flush", e) - } - } finally { - // Ensure resources are cleaned up regardless of exceptions - closeResources() - try { - clearActiveLoggingFileContent() - } catch (e: Exception) { - appLogger.e("Error clearing active logging file content", e) - } + private suspend fun waitForBarrier(marker: String) = withContext(Dispatchers.IO) { + withTimeout(config.flushTimeoutMs.milliseconds) { + while (!containsBarrier(marker)) delay(FLUSH_POLL_INTERVAL_MS.milliseconds) } } - private fun closeResources() { - try { - bufferedWriter?.close() - } catch (e: Exception) { - appLogger.e("Error closing buffered writer", e) - } finally { - bufferedWriter = null + private fun containsBarrier(marker: String): Boolean = logsDirectory.listFiles() + ?.filter { it.name == activeLoggingFile.name || ROLLED_LOG_FILE_REGEX.matches(it.name) } + ?.any { file -> runCatching { file.useLines { lines -> lines.any { marker in it } } }.getOrDefault(false) } + ?: false + + private fun ensureLogDirectoryExists() { + if (!logsDirectory.exists() && !logsDirectory.mkdirs()) { + throw IOException("Unable to create log directory: ${logsDirectory.absolutePath}") } } /** - * Manually flushes any buffered log entries to the file. - * This is useful before sharing logs to ensure all recent entries are included. + * Transfers the only legacy active log to a deterministic gzip snapshot. The active source + * remains untouched until the snapshot has been fully written, validated and renamed. */ - override suspend fun forceFlush() { - try { - withTimeout(config.flushTimeoutMs) { - bufferMutex.withLock { - flushBuffer() - } + private fun migrateLegacyLogs() { + val legacyActiveFile = File(logsDirectory, LEGACY_ACTIVE_FILE_NAME) + val legacySnapshot = File(logsDirectory, LEGACY_SNAPSHOT_FILE_NAME) + val legacySnapshotTemp = File(logsDirectory, "$LEGACY_SNAPSHOT_FILE_NAME.tmp") + + when { + !legacyActiveFile.exists() && legacySnapshot.isFile && isReadableGzip(legacySnapshot) -> { + deleteLegacyLogFiles(keepSnapshot = true) } - } catch (e: TimeoutCancellationException) { - appLogger.w("Force flush operation timed out after ${config.flushTimeoutMs}ms") - throw e - } catch (e: Exception) { - appLogger.e("Error during force flush", e) - throw e - } - } - - private fun clearActiveLoggingFileContent() { - if (activeLoggingFile.exists()) { - PrintWriter(activeLoggingFile).use { writer -> - writer.print("") + !legacyActiveFile.exists() -> legacySnapshotTemp.delete() + legacySnapshot.isFile && isReadableGzip(legacySnapshot) -> { + deleteLegacyLogFiles(keepSnapshot = true) } - } - } - - /** - * Writes the new [text] and other log entries in logcat to the [activeLoggingFile]. - * @return The length, in bytes, of the log file. - */ - private suspend fun writeLineToFile(text: String): Long = withContext(Dispatchers.IO) { - try { - withTimeout(config.bufferLockTimeoutMs) { - bufferMutex.withLock { - logBuffer.add(text) - - val currentTime = System.currentTimeMillis() - val shouldFlush = logBuffer.size >= config.maxBufferSize || - ((currentTime - lastFlushTime) >= config.flushIntervalMs) - - if (shouldFlush) { - flushBuffer() - lastFlushTime = currentTime - } - - return@withLock activeLoggingFile.length() - } + legacySnapshot.exists() && !legacySnapshot.delete() -> Unit + legacySnapshotTemp.exists() && !legacySnapshotTemp.delete() -> Unit + createLegacySnapshot(legacyActiveFile, legacySnapshotTemp, legacySnapshot) -> { + deleteLegacyLogFiles(keepSnapshot = true) } - } catch (e: TimeoutCancellationException) { - appLogger.w("Buffer write operation timed out, log line may be lost: $text") - // Return current file length as fallback - return@withContext activeLoggingFile.length() - } catch (e: Exception) { - appLogger.e("Error writing to log buffer", e) - return@withContext activeLoggingFile.length() } } - private fun ensureLogDirectoryAndFileExistence() { - if (!logsDirectory.exists() && !logsDirectory.mkdirs()) { - appLogger.e("Unable to create logs directory") - } - - if (!activeLoggingFile.exists() && !activeLoggingFile.createNewFile()) { - appLogger.e("KaliumFileWriter: Failure to create new file for logging", IOException("Unable to load log file")) - } - if (!activeLoggingFile.canWrite()) { - appLogger.e("KaliumFileWriter: Logging file is not writable", IOException("Log file not writable")) + private fun createLegacySnapshot(source: File, temporarySnapshot: File, finalSnapshot: File): Boolean = runCatching { + source.inputStream().buffered().use { input -> + GZIPOutputStream(temporarySnapshot.outputStream().buffered()).use { output -> input.copyTo(output) } } + temporarySnapshot.renameTo(finalSnapshot) && isReadableGzip(finalSnapshot) + }.getOrDefault(false).also { created -> + if (!created) temporarySnapshot.delete() } - override fun deleteAllLogFiles() { - clearActiveLoggingFileContent() - logsDirectory.listFiles()?.filter { - it.extension.lowercase(Locale.ROOT) == LOG_COMPRESSED_FILE_EXTENSION - }?.forEach { it.delete() } - } - - private fun getCompressedFilesList() = (logsDirectory.listFiles() ?: emptyArray()).filter { - it != activeLoggingFile && !it.name.endsWith(".tmp") - } - - private fun compressedFileName(): String { - val currentDate = logFileTimeFormat.format(Date()) - return "${LOG_FILE_PREFIX}_$currentDate.$LOG_COMPRESSED_FILE_EXTENSION" - } - - private fun deleteOldCompressedFiles() = getCompressedFilesList() - .sortedBy { it.lastModified() } - .dropLast(LOG_COMPRESSED_FILES_MAX_COUNT) - .forEach { - it.delete() + private fun isReadableGzip(file: File): Boolean = runCatching { + GZIPInputStream(file.inputStream().buffered()).use { input -> + val buffer = ByteArray(DEFAULT_BUFFER_SIZE) + while (input.read(buffer) != -1) Unit } + }.isSuccess - private fun cleanupOrphanedTempFiles() { - getListOfOrphanedTempFiles().forEach { tempFile -> - appLogger.i("Found orphaned temp file: ${tempFile.name}, attempting to compress before cleanup") - try { - // Try to salvage the data by compressing it - // The temp file already has the timestamped name, just remove .tmp extension - val compressedFileName = tempFile.name.removeSuffix(".tmp") - val compressedFile = File(logsDirectory, compressedFileName) - compressFileToGzip(tempFile, compressedFile) - appLogger.i("Successfully salvaged orphaned temp file: ${tempFile.name} -> ${compressedFile.name}") - } catch (e: Exception) { - appLogger.w("Failed to compress orphaned temp file: ${tempFile.name}, will delete it", e) - } finally { - // Always delete the temp file after attempting compression - tempFile.delete() + private fun deleteLegacyLogFiles(keepSnapshot: Boolean = false) { + logsDirectory.listFiles() + ?.filter { file -> + file.name == LEGACY_ACTIVE_FILE_NAME || + LEGACY_ARCHIVE_FILE_REGEX.matches(file.name) || + LEGACY_TEMP_FILE_REGEX.matches(file.name) || + (!keepSnapshot && file.name == LEGACY_SNAPSHOT_FILE_NAME) } - } + ?.forEach(File::delete) } - private fun getListOfOrphanedTempFiles(): List { - return try { - logsDirectory.listFiles()?.filter { it.name.endsWith(".tmp") } ?: emptyList() - } catch (e: SecurityException) { - appLogger.e("Error cleaning up orphaned temp files", e) - emptyList() - } - } + private class GatedLogWriter(private val delegate: () -> LogWriter?) : LogWriter() { + private val lock = Any() + private var enabled = false - private fun copyActiveLogFileToTemp(compressedFileName: String): File { - // Temp file has the same name as final compressed file, but with .tmp extension - val tempFile = File(logsDirectory, "$compressedFileName.tmp") - activeLoggingFile.copyTo(tempFile, overwrite = true) - return tempFile - } + fun enable() = synchronized(lock) { enabled = true } - private suspend fun compressFileAsync(sourceFile: File, compressedFileName: String) = withContext(Dispatchers.IO) { - try { - // Just remove .tmp extension from temp file name to get final compressed filename - val compressedFile = File(logsDirectory, compressedFileName) - compressFileToGzip(sourceFile, compressedFile) + fun disable() = synchronized(lock) { enabled = false } - appLogger.i("Log file compressed: ${sourceFile.name} -> ${compressedFile.name}") - } catch (e: Exception) { - appLogger.e("Failed to compress log file: ${sourceFile.name}", e) - } - } + fun flushBarrier(disableAfterWrite: Boolean = false): String? = synchronized(lock) { + if (!enabled) return null - private fun compressFileToGzip(sourceFile: File, targetGzipFile: File) { - GZIPOutputStream(targetGzipFile.outputStream().buffered()).use { gzipOut -> - sourceFile.inputStream().buffered().use { input -> - input.copyTo(gzipOut, config.bufferSizeBytes) - } + val marker = "$FLUSH_MARKER_PREFIX${UUID.randomUUID()}" + delegate()?.log(Severity.Verbose, marker, LOG_TAG, null) + if (disableAfterWrite) enabled = false + marker } - } - - private fun flushBuffer() { - if (logBuffer.isEmpty()) return - try { - // Use BufferedWriter for efficient writing - val writer = bufferedWriter ?: BufferedWriter( - FileWriter(activeLoggingFile, true), - config.bufferSizeBytes - ).also { bufferedWriter = it } - - // Like here one, Write directly from buffer without copying to the .toList() - logBuffer.forEach { line -> - writer.appendLine(line) + override fun log(severity: Severity, message: String, tag: String, throwable: Throwable?) { + synchronized(lock) { + if (enabled) delegate()?.log(severity, message, tag, throwable) } - writer.flush() - - // and here two, Clear only after successful write - logBuffer.clear() - } catch (e: IOException) { - appLogger.e("Failed to flush log buffer", e) } } - companion object { - private const val LOG_TAG = "LogFileWriter" - private const val LOG_FILE_PREFIX = "wire" - private const val ACTIVE_LOGGING_FILE_NAME = "${LOG_FILE_PREFIX}_logs.txt" - private const val LOG_COMPRESSED_FILES_MAX_COUNT = 10 - private const val LOG_COMPRESSED_FILE_EXTENSION = "gz" + private companion object { + const val LOG_FILE_NAME = "wire_logs" + const val LEGACY_ACTIVE_FILE_NAME = "$LOG_FILE_NAME.txt" + const val LEGACY_SNAPSHOT_FILE_NAME = "wire_legacy_active.gz" + const val LOG_TAG = "LogFileWriter" + const val FLUSH_MARKER_PREFIX = "wire-log-flush:" + const val FLUSH_POLL_INTERVAL_MS = 10L + val ROLLED_LOG_FILE_REGEX = Regex("$LOG_FILE_NAME-[0-9]+\\.log") + val LEGACY_ARCHIVE_FILE_REGEX = Regex("wire_\\d{4}-\\d{2}-\\d{2}_\\d{2}-\\d{2}-\\d{2}\\.gz") + val LEGACY_TEMP_FILE_REGEX = Regex("(?:wire_\\d{4}-\\d{2}-\\d{2}_\\d{2}-\\d{2}-\\d{2}\\.gz|$LEGACY_SNAPSHOT_FILE_NAME)\\.tmp") } } diff --git a/app/src/test/kotlin/com/wire/android/util/logging/LogFileWriterImplTest.kt b/app/src/test/kotlin/com/wire/android/util/logging/LogFileWriterImplTest.kt new file mode 100644 index 00000000000..8887e2c932c --- /dev/null +++ b/app/src/test/kotlin/com/wire/android/util/logging/LogFileWriterImplTest.kt @@ -0,0 +1,230 @@ +/* + * Wire + * Copyright (C) 2026 Wire Swiss GmbH + * + * This program is free software: you can redistribute it and/or modify + * it under the terms of the GNU General Public License as published by + * the Free Software Foundation, either version 3 of the License, or + * (at your option) any later version. + */ +package com.wire.android.util.logging + +import co.touchlab.kermit.Severity +import com.wire.android.AppLogger +import com.wire.android.appLogger +import com.wire.kalium.common.logger.CoreLogger +import com.wire.kalium.common.logger.kaliumLogger +import com.wire.kalium.logger.KaliumLogLevel +import com.wire.kalium.logger.KaliumLogger +import kotlinx.coroutines.test.runTest +import org.junit.After +import org.junit.Rule +import org.junit.Test +import org.junit.jupiter.api.Assertions.assertEquals +import org.junit.jupiter.api.Assertions.assertFalse +import org.junit.jupiter.api.Assertions.assertTrue +import org.junit.rules.TemporaryFolder +import java.io.File +import java.util.zip.GZIPInputStream +import java.util.zip.GZIPOutputStream +import java.util.zip.ZipFile + +class LogFileWriterImplTest { + + @get:Rule + val tempDir = TemporaryFolder() + + @After + fun resetLoggers() { + AppLogger.init(KaliumLogger.Config.DISABLED) + CoreLogger.init(KaliumLogger.Config.DISABLED) + } + + @Test + fun `given enabled writer when application and Kalium log then both are persisted`() = runTest { + val writer = newWriter() + writer.start() + val config = KaliumLogger.Config(KaliumLogLevel.INFO, listOf(writer.logWriter)) + AppLogger.init(config) + CoreLogger.init(config) + + appLogger.i("application diagnostic") + kaliumLogger.i("Kalium diagnostic") + writer.forceFlush() + + val logText = writer.activeLoggingFile.readText() + assertTrue(logText.contains("application diagnostic")) + assertTrue(logText.contains("Kalium diagnostic")) + } + + @Test + fun `given stopped writer when logging then diagnostics are not persisted`() = runTest { + val writer = newWriter() + writer.start() + writer.stop() + + writer.logWriter.log(Severity.Info, "disabled diagnostic", "test", null) + writer.forceFlush() + + assertEquals("", writer.activeLoggingFile.readText()) + } + + @Test + fun `given small rolling limit when logging then retained files are bounded`() = runTest { + val writer = newWriter(rollOnSizeBytes = 1, maxLogFiles = 3) + writer.start() + + repeat(5) { index -> + writer.logWriter.log(Severity.Info, "rolling diagnostic $index", "test", null) + writer.forceFlush() + } + + val logFiles = writer.activeLoggingFile.parentFile + ?.listFiles { file -> file.name.matches(Regex("wire_logs(-[0-9]+)?\\.log")) } + .orEmpty() + + assertTrue(logFiles.size <= 3) + assertTrue(logFiles.any { it.name == "wire_logs-1.log" }) + } + + @Test + fun `given deleted logs when logging resumes then active file is cleared and accepts new entries`() = runTest { + val writer = newWriter() + writer.start() + writer.logWriter.log(Severity.Info, "before delete", "test", null) + writer.forceFlush() + + writer.deleteAllLogFiles() + + assertTrue(writer.activeLoggingFile.exists()) + assertEquals("", writer.activeLoggingFile.readText()) + assertFalse(writer.activeLoggingFile.parentFile?.listFiles().orEmpty().any { it.name == "wire_logs-1.log" }) + + writer.logWriter.log(Severity.Info, "after delete", "test", null) + writer.forceFlush() + + assertTrue(writer.activeLoggingFile.readText().contains("after delete")) + } + + @Test + fun `given flushed logs when archiving then the active diagnostic file is included`() = runTest { + val writer = newWriter() + writer.start() + writer.logWriter.log(Severity.Info, "shareable diagnostic", "test", null) + writer.forceFlush() + val archive = File(tempDir.root, "logs.zip") + + createCompressedLogsArchive(writer.activeLoggingFile.parentFile!!, archive) + + ZipFile(archive).use { zip -> + assertTrue(zip.getEntry(writer.activeLoggingFile.name) != null) + val entry = zip.getEntry(writer.activeLoggingFile.name) + val text = zip.getInputStream(entry).bufferedReader().use { it.readText() } + assertTrue(text.contains("shareable diagnostic")) + } + } + + @Test + fun `given legacy log when starting then ZIP export includes one gzip snapshot`() = runTest { + val logsDirectory = tempDir.newFolder("legacy-logs") + val legacyActive = File(logsDirectory, "wire_logs.txt").apply { writeText("legacy diagnostic") } + File(logsDirectory, "wire_2026-08-27_15-09-01.gz").writeText("old archive") + val writer = writerFor(logsDirectory) + + writer.start() + writer.logWriter.log(Severity.Info, "current diagnostic", "test", null) + writer.forceFlush() + val archive = File(tempDir.root, "migrated-logs.zip") + createCompressedLogsArchive(logsDirectory, archive) + + ZipFile(archive).use { zip -> + val legacySnapshot = zip.getEntry("wire_legacy_active.gz") + val legacySnapshotText = zip.getInputStream(legacySnapshot).use { input -> + GZIPInputStream(input).bufferedReader().use { it.readText() } + } + + assertEquals("legacy diagnostic", legacySnapshotText) + val currentLogText = zip.getInputStream(zip.getEntry("wire_logs.log")) + .bufferedReader() + .use { it.readText() } + assertTrue(currentLogText.contains("current diagnostic")) + assertEquals(null, zip.getEntry("wire_logs.txt")) + assertEquals(null, zip.getEntry("wire_2026-08-27_15-09-01.gz")) + } + assertFalse(legacyActive.exists()) + } + + @Test + fun `given finalized snapshot without source when starting then remaining legacy files are cleaned`() = runTest { + val logsDirectory = tempDir.newFolder("interrupted-logs") + File(logsDirectory, "wire_legacy_active.gz").writeGzip("legacy diagnostic") + val legacyArchive = File(logsDirectory, "wire_2026-08-27_15-09-01.gz").apply { writeText("old archive") } + + writerFor(logsDirectory).start() + + assertFalse(legacyArchive.exists()) + assertEquals("legacy diagnostic", File(logsDirectory, "wire_legacy_active.gz").gzipText()) + } + + @Test + fun `given snapshot failure when starting then legacy files remain and direct logging continues`() = runTest { + val logsDirectory = tempDir.newFolder("failed-migration-logs") + val legacyActive = File(logsDirectory, "wire_logs.txt").apply { writeText("legacy diagnostic") } + val legacyArchive = File(logsDirectory, "wire_2026-08-27_15-09-01.gz").apply { writeText("old archive") } + File(logsDirectory, "wire_legacy_active.gz").apply { + mkdir() + File(this, "blocker").writeText("cannot delete") + } + val writer = writerFor(logsDirectory) + + writer.start() + writer.logWriter.log(Severity.Info, "current diagnostic", "test", null) + writer.forceFlush() + + assertTrue(legacyActive.exists()) + assertTrue(legacyArchive.exists()) + assertTrue(writer.activeLoggingFile.readText().contains("current diagnostic")) + } + + @Test + fun `given legacy and direct logs when deleting then recognized files are removed and unrelated files remain`() = runTest { + val writer = newWriter() + writer.start() + File(writer.activeLoggingFile.parentFile, "wire_logs.txt").writeText("legacy active") + File(writer.activeLoggingFile.parentFile, "wire_2026-08-27_15-09-01.gz").writeText("legacy archive") + File(writer.activeLoggingFile.parentFile, "wire_legacy_active.gz").writeGzip("legacy snapshot") + val unrelatedFile = File(writer.activeLoggingFile.parentFile, "unrelated.gz").apply { writeText("keep") } + + writer.deleteAllLogFiles() + + assertFalse(File(writer.activeLoggingFile.parentFile, "wire_logs.txt").exists()) + assertFalse(File(writer.activeLoggingFile.parentFile, "wire_2026-08-27_15-09-01.gz").exists()) + assertFalse(File(writer.activeLoggingFile.parentFile, "wire_legacy_active.gz").exists()) + assertTrue(unrelatedFile.exists()) + } + + private fun newWriter( + rollOnSizeBytes: Long = 25 * 1024 * 1024L, + maxLogFiles: Int = 10, + ) = LogFileWriterImpl( + logsDirectory = tempDir.newFolder("logs"), + config = LogFileWriterConfig( + rollOnSizeBytes = rollOnSizeBytes, + maxLogFiles = maxLogFiles, + ) + ) + + private fun writerFor(logsDirectory: File) = LogFileWriterImpl( + logsDirectory = logsDirectory, + config = LogFileWriterConfig( + rollOnSizeBytes = 25 * 1024 * 1024L, + maxLogFiles = 10, + ) + ) + + private fun File.writeGzip(contents: String) { + GZIPOutputStream(outputStream()).bufferedWriter().use { it.write(contents) } + } + + private fun File.gzipText(): String = GZIPInputStream(inputStream()).bufferedReader().use { it.readText() } +} diff --git a/docs/adr/0015-migrate-legacy-diagnostic-logs.md b/docs/adr/0015-migrate-legacy-diagnostic-logs.md new file mode 100644 index 00000000000..a951cd084a4 --- /dev/null +++ b/docs/adr/0015-migrate-legacy-diagnostic-logs.md @@ -0,0 +1,59 @@ +# 15. Replace logcat-process capture with direct diagnostic file logging + +Date: 2026-09-02 + +## Status + +Accepted + +## Context + +The previous Android diagnostic logger started a `logcat` process and copied its output into +`wire_logs.txt`, with timestamped gzip rolls. That approach depends on device-specific logcat +availability, permissions and process behavior. It can produce empty diagnostic files on some +OEM/vendor devices even while the application is running normally, which makes support reports +unreliable precisely where logs are needed most. + +Application and Kalium diagnostics already flow through Kermit. Writing that stream directly to a +rolling file avoids relying on the platform logcat process. The direct writer stores +`wire_logs.log` and numbered rolls in the same directory, so upgraded installations also need a +safe transition for existing legacy files. + +The current app packages diagnostic files into a single ZIP archive. This established export +behavior must be retained while preserving a useful legacy diagnostic snapshot and avoiding data +loss if migration is interrupted or filesystem operations fail. + +## Decision + +The app writes Kermit diagnostics directly to a rolling file and does not use a `logcat` process +for diagnostic file collection. Application and Kalium log writers feed the same direct writer, +subject to the existing logging enablement and log-level configuration. + +When direct file logging starts, the app migrates a legacy `wire_logs.txt` file before opening the +rolling writer. + +- Compress the legacy active file into the deterministic `wire_legacy_active.gz` through a + temporary sibling file. +- Validate and finalize the gzip snapshot before deleting the legacy source. +- After a valid snapshot exists, remove only recognized legacy archives and temporary remnants. +- On startup after an interruption, treat a valid snapshot as the committed state and finish + cleanup without creating another snapshot. +- If compression or finalization fails, retain the legacy source and history, then continue with + direct logging. +- Delete logs removes recognized legacy files, the retained snapshot, and direct rolling files; + unrelated files in the directory are preserved. +- Diagnostic sharing remains a single ZIP archive. The snapshot is included naturally as an entry + alongside current rolling logs. + +## Consequences + +Diagnostic logging no longer depends on an OEM's logcat process behavior, so files contain the +events emitted by the application's configured Kermit writers on supported devices. Users retain +at most one compressed view of the legacy active log after upgrade, and support exports contain +both pre-upgrade and current diagnostics without changing their ZIP format. + +The direct approach records only logs routed through Kermit; it intentionally does not capture +arbitrary system or third-party logcat output. Migration adds a small amount of filesystem work on +the first enabled direct-logging startup and requires focused tests for successful migration, +failed finalization, restart recovery, deletion, and ZIP contents. The filename allow-list must +be maintained if diagnostic log naming changes. diff --git a/gradle/libs.versions.toml b/gradle/libs.versions.toml index 05bc6b5c8f3..92243cf01e3 100644 --- a/gradle/libs.versions.toml +++ b/gradle/libs.versions.toml @@ -91,6 +91,7 @@ aboutLibraries = "14.0.0-b03" cyclonedx = "3.1.0" leakCanary = "2.14" ksp = "2.3.7" +kermitIo = "2.0.5" # Benchmark benchmark-macro-junit4 = "1.4.1" @@ -169,6 +170,7 @@ libsodium-bindings-jvm = { module = "com.ionspin.kotlin:multiplatform-crypto-lib ksp-symbol-processing-api = { module = "com.google.devtools.ksp:symbol-processing-api", version.ref = "ksp" } ksp-symbol-processing-plugin = { module = "com.google.devtools.ksp:symbol-processing-gradle-plugin", version.ref = "ksp" } +kermit-io = { module = "co.touchlab:kermit-io", version.ref = "kermitIo" } allure-kotlin-model = { module = "io.qameta.allure:allure-kotlin-model", version.ref = "allureKotlin" } allure-kotlin-commons = { module = "io.qameta.allure:allure-kotlin-commons", version.ref = "allureKotlin" }