From 3535375e75f6041fe89f16435abc657d38881dfc Mon Sep 17 00:00:00 2001 From: Sam Hill Date: Wed, 25 Feb 2026 15:12:43 -0500 Subject: [PATCH 1/4] Catch io exceptions in file logger --- .../kermit/io/RollingFileLogWriter.kt | 90 ++++++++++++++++--- 1 file changed, 76 insertions(+), 14 deletions(-) diff --git a/kermit-io/src/commonMain/kotlin/co/touchlab/kermit/io/RollingFileLogWriter.kt b/kermit-io/src/commonMain/kotlin/co/touchlab/kermit/io/RollingFileLogWriter.kt index a2d66d29..37d6ca14 100644 --- a/kermit-io/src/commonMain/kotlin/co/touchlab/kermit/io/RollingFileLogWriter.kt +++ b/kermit-io/src/commonMain/kotlin/co/touchlab/kermit/io/RollingFileLogWriter.kt @@ -65,7 +65,7 @@ import kotlinx.io.writeString * Path(context.filesDir.path) * ``` * - * and on iOS this wil return the application's sandboxed document directory: + * and on iOS this will return the application's sandboxed document directory: * * ```kotlin * (NSFileManager.defaultManager.URLsForDirectory(NSDocumentDirectory, NSUserDomainMask).last() as NSURL).path!! @@ -73,6 +73,28 @@ import kotlinx.io.writeString * * However, you can use any path that is writable by the application. This would generally be implemented by * platform-specific code. + * + * ## iOS background logging + * + * On iOS, files created in the Documents directory inherit the `NSFileProtectionComplete` data protection + * class by default. This prevents any file access while the device is locked, causing log writes to fail + * with an `IOException` when your app runs in the background on a locked device. + * + * If you need to write logs while the device is locked (e.g. during background tasks), set the file + * protection attribute on your log directory to `NSFileProtectionCompleteUntilFirstUserAuthentication` + * before creating the writer. This allows file access after the first unlock following a reboot: + * + * ```kotlin + * // iOS-specific setup (place in your iOS source set) + * NSFileManager.defaultManager.setAttributes( + * mapOf(NSFileProtectionKey to NSFileProtectionCompleteUntilFirstUserAuthentication), + * ofItemAtPath = logDirectoryPath, + * error = null, + * ) + * ``` + * + * When file access is unavailable (e.g. device locked with default protection), `RollingFileLogWriter` + * will suppress the error and discard log messages until access is restored, rather than crashing. */ open class RollingFileLogWriter( private val config: RollingFileLogWriterConfig, @@ -168,33 +190,73 @@ open class RollingFileLogWriter( private suspend fun writer() { val logFilePath = pathForLogIndex(0) - if (fileSystem.exists(logFilePath) && shouldRollLogs(logFilePath)) { - rollLogs() + try { + if (fileSystem.exists(logFilePath) && shouldRollLogs(logFilePath)) { + rollLogs() + } + } catch (e: IOException) { + println("RollingFileLogWriter: Failed to roll logs at startup: ${e.message}") } fun createNewLogSink(): Sink = fileSystem .sink(logFilePath, append = true) .buffered() - var currentLogSink: Sink = createNewLogSink() + var currentLogSink: Sink? = try { + createNewLogSink() + } catch (e: IOException) { + println("RollingFileLogWriter: Failed to open log file: ${e.message}") + null + } + + // Tracks whether we are currently in an error state to avoid spamming stderr on every write + var ioErrorActive = false while (currentCoroutineContext().isActive) { // wait for data to be available, flush periodically val result = loggingChannel.receiveCatching() - // check if logs need rolling - if (shouldRollLogs(logFilePath)) { - currentLogSink.close() - rollLogs() - currentLogSink = createNewLogSink() - } + try { + if (currentLogSink == null) { + currentLogSink = createNewLogSink() + } + + // check if logs need rolling + if (shouldRollLogs(logFilePath)) { + currentLogSink.close() + rollLogs() + currentLogSink = createNewLogSink() + } + + result.getOrNull()?.transferTo(currentLogSink) - result.getOrNull()?.transferTo(currentLogSink) + // we could improve performance by flushing less frequently at the cost of potential data loss, + // but this is a safe default + currentLogSink.flush() - // we could improve performance by flushing less frequently at the cost of potential data loss, - // but this is a safe default - currentLogSink.flush() + if (ioErrorActive) { + println("RollingFileLogWriter: Log file access restored") + ioErrorActive = false + } + } catch (e: IOException) { + // On iOS, file I/O fails when the device is locked and the app is in the background + // (see NSFileProtectionComplete). We catch the exception here to keep the writer + // coroutine alive so that logging can resume once file access is restored. + if (!ioErrorActive) { + println("RollingFileLogWriter: IOException writing to log file, some logs may be lost: ${e.message}") + e.printStackTrace() + ioErrorActive = true + } + try { + currentLogSink?.close() + } catch (_: IOException) { + // ignore close failure + } + currentLogSink = null + } } + + currentLogSink?.close() } private fun fileSizeOrZero(path: Path) = fileSystem.metadataOrNull(path)?.size ?: 0 From b9163ac8eed1dabd2faacdb21988570145587cec Mon Sep 17 00:00:00 2001 From: Sam Hill Date: Wed, 11 Mar 2026 14:55:40 -0400 Subject: [PATCH 2/4] Reorganize loop --- .../kermit/io/RollingFileLogWriter.kt | 25 +++++-------------- 1 file changed, 6 insertions(+), 19 deletions(-) diff --git a/kermit-io/src/commonMain/kotlin/co/touchlab/kermit/io/RollingFileLogWriter.kt b/kermit-io/src/commonMain/kotlin/co/touchlab/kermit/io/RollingFileLogWriter.kt index 37d6ca14..b2c04810 100644 --- a/kermit-io/src/commonMain/kotlin/co/touchlab/kermit/io/RollingFileLogWriter.kt +++ b/kermit-io/src/commonMain/kotlin/co/touchlab/kermit/io/RollingFileLogWriter.kt @@ -190,24 +190,11 @@ open class RollingFileLogWriter( private suspend fun writer() { val logFilePath = pathForLogIndex(0) - try { - if (fileSystem.exists(logFilePath) && shouldRollLogs(logFilePath)) { - rollLogs() - } - } catch (e: IOException) { - println("RollingFileLogWriter: Failed to roll logs at startup: ${e.message}") - } - fun createNewLogSink(): Sink = fileSystem .sink(logFilePath, append = true) .buffered() - var currentLogSink: Sink? = try { - createNewLogSink() - } catch (e: IOException) { - println("RollingFileLogWriter: Failed to open log file: ${e.message}") - null - } + var currentLogSink: Sink? = null // Tracks whether we are currently in an error state to avoid spamming stderr on every write var ioErrorActive = false @@ -217,17 +204,17 @@ open class RollingFileLogWriter( val result = loggingChannel.receiveCatching() try { - if (currentLogSink == null) { - currentLogSink = createNewLogSink() - } - // check if logs need rolling if (shouldRollLogs(logFilePath)) { - currentLogSink.close() + currentLogSink?.close() rollLogs() currentLogSink = createNewLogSink() } + if (currentLogSink == null) { + currentLogSink = createNewLogSink() + } + result.getOrNull()?.transferTo(currentLogSink) // we could improve performance by flushing less frequently at the cost of potential data loss, From 7c98854b6a6b042a16604b330a0213cc362fd019 Mon Sep 17 00:00:00 2001 From: Sam Hill Date: Wed, 11 Mar 2026 15:53:27 -0400 Subject: [PATCH 3/4] Add basic tests for RollingFileLogWriter --- .../kermit/io/RollingFileLogWriter.kt | 58 +++--- .../kermit/io/RollingFileLogWriterTest.kt | 170 ++++++++++++++++++ 2 files changed, 196 insertions(+), 32 deletions(-) create mode 100644 kermit-io/src/commonTest/kotlin/co/touchlab/kermit/io/RollingFileLogWriterTest.kt diff --git a/kermit-io/src/commonMain/kotlin/co/touchlab/kermit/io/RollingFileLogWriter.kt b/kermit-io/src/commonMain/kotlin/co/touchlab/kermit/io/RollingFileLogWriter.kt index b2c04810..8b7c849f 100644 --- a/kermit-io/src/commonMain/kotlin/co/touchlab/kermit/io/RollingFileLogWriter.kt +++ b/kermit-io/src/commonMain/kotlin/co/touchlab/kermit/io/RollingFileLogWriter.kt @@ -46,55 +46,47 @@ import kotlinx.io.writeString /** * Implements a log writer that writes log messages to a rolling file. * - * It also deletes old log files when the maximum number of log files is reached. We simply keep - * approximately [RollingFileLogWriterConfig.rollOnSize] bytes in each log file, - * and delete the oldest file when we have more than [RollingFileLogWriterConfig.maxLogFiles]. + * It also deletes old log files when the maximum number of log files is reached. We simply keep approximately + * [RollingFileLogWriterConfig.rollOnSize] bytes in each log file, and delete the oldest file when we have more than + * [RollingFileLogWriterConfig.maxLogFiles]. * - * Formatting is governed by the passed [MessageStringFormatter], but we do prepend a timestamp by default. - * Turn this off via [RollingFileLogWriterConfig.prependTimestamp] + * Formatting is governed by the passed [MessageStringFormatter], but we do prepend a timestamp by default. Turn this off via + * [RollingFileLogWriterConfig.prependTimestamp] * - * Writes to the file are done by a different coroutine. The main reason for this is to make writes to the - * log file sink thread-safe, and so that file rolling can be performed without additional synchronization - * or locking. The channel that buffers log messages is currently unbuffered, so logging threads will block - * until the I/O is complete. However, buffering could easily be introduced to potentially increase logging - * throughput. The envisioned usage scenarios for this class probably do not warrant this. + * Writes to the file are done by a different coroutine. The main reason for this is to make writes to the log file sink thread-safe, and + * so that file rolling can be performed without additional synchronization or locking. The channel that buffers log messages is currently + * unbuffered, so logging threads will block until the I/O is complete. However, buffering could easily be introduced to potentially + * increase logging throughput. The envisioned usage scenarios for this class probably do not warrant this. * * The recommended way to obtain the logPath on Android is: - * * ```kotlin * Path(context.filesDir.path) * ``` * * and on iOS this will return the application's sandboxed document directory: - * * ```kotlin * (NSFileManager.defaultManager.URLsForDirectory(NSDocumentDirectory, NSUserDomainMask).last() as NSURL).path!! * ``` * - * However, you can use any path that is writable by the application. This would generally be implemented by - * platform-specific code. + * However, you can use any path that is writable by the application. This would generally be implemented by platform-specific code. * * ## iOS background logging * - * On iOS, files created in the Documents directory inherit the `NSFileProtectionComplete` data protection - * class by default. This prevents any file access while the device is locked, causing log writes to fail - * with an `IOException` when your app runs in the background on a locked device. + * On iOS, files created may inherit the `NSFileProtectionComplete` data protection class. This prevents any file access while the device is + * locked, causing log writes to fail with an `IOException` when your app runs in the background on a locked device. * - * If you need to write logs while the device is locked (e.g. during background tasks), set the file - * protection attribute on your log directory to `NSFileProtectionCompleteUntilFirstUserAuthentication` - * before creating the writer. This allows file access after the first unlock following a reboot: - * - * ```kotlin - * // iOS-specific setup (place in your iOS source set) - * NSFileManager.defaultManager.setAttributes( - * mapOf(NSFileProtectionKey to NSFileProtectionCompleteUntilFirstUserAuthentication), - * ofItemAtPath = logDirectoryPath, - * error = null, + * If you need to write logs while the device is locked (e.g. during background tasks), set the file protection attribute on your log + * directory to `NSFileProtectionCompleteUntilFirstUserAuthentication` before creating the writer. This allows file access after the first + * unlock following a reboot: + * ```swift + * try FileManager.default.setAttributes( + * [.protectionKey: FileProtectionType.completeUntilFirstUserAuthentication], + * ofItemAtPath: logDirectoryPath * ) * ``` * - * When file access is unavailable (e.g. device locked with default protection), `RollingFileLogWriter` - * will suppress the error and discard log messages until access is restored, rather than crashing. + * When file access is unavailable (e.g. device locked with default protection), `RollingFileLogWriter` will suppress the error and discard + * log messages until access is restored, rather than crashing. */ open class RollingFileLogWriter( private val config: RollingFileLogWriterConfig, @@ -174,9 +166,11 @@ open class RollingFileLogWriter( } catch (e: IOException) { // we can't log it, we're the logger -- print to standard error println( - "RollingFileLogWriter: Failed to roll log file $sourcePath to $targetPath (sourcePath exists=${fileSystem.exists( - sourcePath, - )})", + "RollingFileLogWriter: Failed to roll log file $sourcePath to $targetPath (sourcePath exists=${ + fileSystem.exists( + sourcePath, + ) + })", ) e.printStackTrace() } diff --git a/kermit-io/src/commonTest/kotlin/co/touchlab/kermit/io/RollingFileLogWriterTest.kt b/kermit-io/src/commonTest/kotlin/co/touchlab/kermit/io/RollingFileLogWriterTest.kt new file mode 100644 index 00000000..33dfc707 --- /dev/null +++ b/kermit-io/src/commonTest/kotlin/co/touchlab/kermit/io/RollingFileLogWriterTest.kt @@ -0,0 +1,170 @@ +/* + * Copyright (c) 2026 Touchlab + * Licensed under the Apache License, Version 2.0 (the "License"); you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software distributed under the License is distributed on an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the License for the specific language governing permissions and limitations under the License. + */ + +package co.touchlab.kermit.io + +import co.touchlab.kermit.Severity +import kotlin.test.Test +import kotlin.test.assertFalse +import kotlin.test.assertTrue +import kotlinx.coroutines.delay +import kotlinx.coroutines.runBlocking +import kotlinx.io.buffered +import kotlinx.io.files.Path +import kotlinx.io.files.SystemFileSystem +import kotlinx.io.readString + +class RollingFileLogWriterTest { + + private fun createTempDir(): Path { + val base = Path(SystemFileSystem.resolve(Path(".")), "build", "tmp", "test-logs-${randomSuffix()}") + SystemFileSystem.createDirectories(base) + return base + } + + private fun randomSuffix(): String = (0..7).map { ('a'..'z').random() }.joinToString("") + + private fun readFileText(path: Path): String = SystemFileSystem.source(path).buffered().readString() + + private fun createWriter( + dir: Path, + fileName: String = "test", + rollOnSize: Long = 10 * 1024 * 1024, + maxLogFiles: Int = 5, + ): RollingFileLogWriter = RollingFileLogWriter( + config = RollingFileLogWriterConfig( + logFileName = fileName, + logFilePath = dir, + rollOnSize = rollOnSize, + maxLogFiles = maxLogFiles, + prependTimestamp = false, + logTag = false, + ), + ) + + private fun deleteRecursively(dir: Path) { + try { + SystemFileSystem.list(dir).forEach { path -> + SystemFileSystem.delete(path) + } + SystemFileSystem.delete(dir) + } catch (_: Exception) { + // best-effort cleanup + } + } + + /** + * Give the writer coroutine time to process log messages. + */ + private suspend fun waitForWrite() { + delay(200) + } + + @Test + fun writesLogMessageToFile() = runBlocking { + val dir = createTempDir() + try { + val writer = createWriter(dir) + writer.log(Severity.Info, "Hello Kermit", "TestTag", null) + waitForWrite() + + val logFile = Path(dir, "test.log") + assertTrue(SystemFileSystem.exists(logFile), "Log file should exist") + + val content = readFileText(logFile) + assertTrue(content.contains("Hello Kermit"), "Log file should contain the message") + } finally { + deleteRecursively(dir) + } + } + + @Test + fun appendsMultipleMessages() = runBlocking { + val dir = createTempDir() + try { + val writer = createWriter(dir) + writer.log(Severity.Info, "First message", "Tag", null) + writer.log(Severity.Warn, "Second message", "Tag", null) + waitForWrite() + + val content = readFileText(Path(dir, "test.log")) + assertTrue(content.contains("First message")) + assertTrue(content.contains("Second message")) + } finally { + deleteRecursively(dir) + } + } + + @Test + fun rollsFileWhenSizeExceeded() = runBlocking { + val dir = createTempDir() + try { + // Use a very small roll size to trigger rolling + val writer = createWriter(dir, rollOnSize = 50) + + // Write enough to exceed the roll size + repeat(5) { + writer.log(Severity.Info, "Log message number $it that is long enough to exceed the limit", "Tag", null) + waitForWrite() + } + + val primaryLog = Path(dir, "test.log") + val rolledLog = Path(dir, "test-1.log") + + assertTrue(SystemFileSystem.exists(primaryLog), "Primary log file should exist") + assertTrue(SystemFileSystem.exists(rolledLog), "Rolled log file should exist") + } finally { + deleteRecursively(dir) + } + } + + @Test + fun deletesOldestFileWhenMaxReached() = runBlocking { + val dir = createTempDir() + try { + // maxLogFiles=2 means we keep test.log and test-1.log, delete anything older + val writer = createWriter(dir, rollOnSize = 50, maxLogFiles = 2) + + // Write enough messages to trigger multiple rolls + repeat(10) { + writer.log(Severity.Info, "Log message number $it that is long enough to exceed the small limit", "Tag", null) + waitForWrite() + } + + val primaryLog = Path(dir, "test.log") + val rolledLog1 = Path(dir, "test-1.log") + val rolledLog2 = Path(dir, "test-2.log") + + assertTrue(SystemFileSystem.exists(primaryLog), "Primary log should exist") + assertTrue(SystemFileSystem.exists(rolledLog1), "First rolled log should exist") + assertFalse(SystemFileSystem.exists(rolledLog2), "Second rolled log should not exist (maxLogFiles=2)") + } finally { + deleteRecursively(dir) + } + } + + @Test + fun includesThrowableStackTrace() = runBlocking { + val dir = createTempDir() + try { + val writer = createWriter(dir) + val exception = RuntimeException("test error") + writer.log(Severity.Error, "Error occurred", "Tag", exception) + waitForWrite() + + val content = readFileText(Path(dir, "test.log")) + assertTrue(content.contains("Error occurred")) + assertTrue(content.contains("RuntimeException"), "Should contain exception class name") + assertTrue(content.contains("test error"), "Should contain exception message") + } finally { + deleteRecursively(dir) + } + } +} From 46e455ef5f7f8ab113fd996bb569628b6b4c8ff4 Mon Sep 17 00:00:00 2001 From: Sam Hill Date: Mon, 16 Mar 2026 13:58:45 -0400 Subject: [PATCH 4/4] Handle Windows file size not updating --- .../kermit/io/RollingFileLogWriter.kt | 21 ++++++++++++------- .../kermit/io/RollingFileLogWriterTest.kt | 6 ++++++ 2 files changed, 20 insertions(+), 7 deletions(-) diff --git a/kermit-io/src/commonMain/kotlin/co/touchlab/kermit/io/RollingFileLogWriter.kt b/kermit-io/src/commonMain/kotlin/co/touchlab/kermit/io/RollingFileLogWriter.kt index 8b7c849f..164cf289 100644 --- a/kermit-io/src/commonMain/kotlin/co/touchlab/kermit/io/RollingFileLogWriter.kt +++ b/kermit-io/src/commonMain/kotlin/co/touchlab/kermit/io/RollingFileLogWriter.kt @@ -18,6 +18,7 @@ import co.touchlab.kermit.Message import co.touchlab.kermit.MessageStringFormatter import co.touchlab.kermit.Severity import co.touchlab.kermit.Tag +import kotlin.math.max import kotlin.time.Clock import kotlin.time.ExperimentalTime import kotlinx.coroutines.CoroutineExceptionHandler @@ -148,10 +149,8 @@ open class RollingFileLogWriter( private fun formatMessage(severity: Severity, tag: Tag?, message: Message): String = messageStringFormatter.formatMessage(severity, if (config.logTag) tag else null, message) - private fun shouldRollLogs(logFilePath: Path): Boolean { - val size = fileSizeOrZero(logFilePath) - return size > config.rollOnSize - } + private fun shouldRollLogs(currentSize: Long, logFilePath: Path): Boolean = + max(currentSize, fileSizeOrZero(logFilePath)) > config.rollOnSize private fun rollLogs() { if (fileSystem.exists(pathForLogIndex(config.maxLogFiles - 1))) { @@ -189,8 +188,11 @@ open class RollingFileLogWriter( .buffered() var currentLogSink: Sink? = null + // Track file size internally to avoid relying on filesystem metadata, which can be + // stale on Windows while a write handle is open. + var currentFileSize = fileSizeOrZero(logFilePath) - // Tracks whether we are currently in an error state to avoid spamming stderr on every write + // Tracks whether we are currently in an error state to avoid spamming on every write var ioErrorActive = false while (currentCoroutineContext().isActive) { @@ -199,17 +201,21 @@ open class RollingFileLogWriter( try { // check if logs need rolling - if (shouldRollLogs(logFilePath)) { + if (shouldRollLogs(currentFileSize, logFilePath)) { currentLogSink?.close() rollLogs() currentLogSink = createNewLogSink() + currentFileSize = 0 } if (currentLogSink == null) { currentLogSink = createNewLogSink() } - result.getOrNull()?.transferTo(currentLogSink) + val data = result.getOrNull() + val bytesWritten = data?.size ?: 0 + data?.transferTo(currentLogSink) + currentFileSize += bytesWritten // we could improve performance by flushing less frequently at the cost of potential data loss, // but this is a safe default @@ -234,6 +240,7 @@ open class RollingFileLogWriter( // ignore close failure } currentLogSink = null + currentFileSize = fileSizeOrZero(logFilePath) } } diff --git a/kermit-io/src/commonTest/kotlin/co/touchlab/kermit/io/RollingFileLogWriterTest.kt b/kermit-io/src/commonTest/kotlin/co/touchlab/kermit/io/RollingFileLogWriterTest.kt index 33dfc707..84ca8663 100644 --- a/kermit-io/src/commonTest/kotlin/co/touchlab/kermit/io/RollingFileLogWriterTest.kt +++ b/kermit-io/src/commonTest/kotlin/co/touchlab/kermit/io/RollingFileLogWriterTest.kt @@ -117,9 +117,15 @@ class RollingFileLogWriterTest { val primaryLog = Path(dir, "test.log") val rolledLog = Path(dir, "test-1.log") + val rolledLog2 = Path(dir, "test-2.log") + val rolledLog3 = Path(dir, "test-3.log") + val rolledLog4 = Path(dir, "test-4.log") assertTrue(SystemFileSystem.exists(primaryLog), "Primary log file should exist") assertTrue(SystemFileSystem.exists(rolledLog), "Rolled log file should exist") + assertTrue(SystemFileSystem.exists(rolledLog2), "Rolled log file should exist") + assertTrue(SystemFileSystem.exists(rolledLog3), "Rolled log file should exist") + assertTrue(SystemFileSystem.exists(rolledLog4), "Rolled log file should exist") } finally { deleteRecursively(dir) }