Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[#115] Improved log file auto rotation; now attaching last 2 files to user reports #116

Merged
merged 13 commits into from
Aug 14, 2023
4 changes: 4 additions & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -3,6 +3,10 @@ All notable changes to this project will be documented in this file.

The format is based on the Steamclock [Release Management Guide](https://github.com/steamclock/labs/wiki/Release-Management-Guide).

## Unreleased
- Allow more than one log to be attached to a Sentry report (#115)


## Jitpack v2.3 : Jun 19, 2023
- Added UserReports (#110)
- Updated Sentry plugin version; added exclusion for "default" Timber/Sentry integration (#111)
Expand Down
6 changes: 2 additions & 4 deletions app/src/main/java/com/steamclock/steamclogsample/App.kt
Original file line number Diff line number Diff line change
@@ -1,10 +1,7 @@
package com.steamclock.steamclogsample

import android.app.Application
import com.steamclock.steamclog.Config
import com.steamclock.steamclog.ExtraInfoPurpose
import com.steamclock.steamclog.FilterOut
import com.steamclock.steamclog.clog
import com.steamclock.steamclog.*

/**
* steamclog
Expand All @@ -16,6 +13,7 @@ class App : Application() {
clog.initWith(Config(
isDebug = BuildConfig.DEBUG,
fileWritePath = externalCacheDir,
autoRotateConfig = AutoRotateConfig(10L), // Short rotate so we can more easily test
filtering = appFiltering,
detailedLogsOnUserReports = true,
extraInfo = { purpose ->
Expand Down
13 changes: 12 additions & 1 deletion app/src/main/java/com/steamclock/steamclogsample/MainActivity.kt
Original file line number Diff line number Diff line change
Expand Up @@ -13,6 +13,8 @@ import com.steamclock.steamclogsample.databinding.ActivityMainBinding
import kotlinx.coroutines.Dispatchers
import kotlinx.coroutines.GlobalScope
import kotlinx.coroutines.launch
import java.text.SimpleDateFormat
import java.util.Date


class MainActivity : AppCompatActivity() {
Expand Down Expand Up @@ -205,7 +207,16 @@ class MainActivity : AppCompatActivity() {
}

private fun testLogDump() = GlobalScope.launch(Dispatchers.Main) {
binding.demoText.text = SteamcLog.getFullLogContents()
var logMetaData = "Log files (Last modified descending): \n\n"
SteamcLog.getAllLogFiles(LogSort.LastModifiedDesc)?.forEachIndexed { index, file ->
val lastModified = SimpleDateFormat("dd-MM HH:mm:ss").format(Date(file.lastModified()))
val fileSizeInBytes = file.length() / 1024
val fileData = "$index: $lastModified ${file.name} (${fileSizeInBytes}b)"
logMetaData += fileData + "\n"
}

logMetaData += "\nFull Content:\n\n" + SteamcLog.getFullLogContents()
binding.demoText.text = logMetaData
Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Updating sample app to print out the list of log files so I can properly test the auto rotation feature

}

private fun simulateCrash() {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -12,6 +12,6 @@ data class AutoRotateConfig(
val fileRotationSeconds: Long = defaultFileRotationSeconds // matching iOS
) {
companion object {
const val defaultFileRotationSeconds = 600L
const val defaultFileRotationSeconds = 600L // 600 secs = 10 mins
}
}
97 changes: 72 additions & 25 deletions steamclog/src/main/java/com/steamclock/steamclog/Destinations.kt
Original file line number Diff line number Diff line change
Expand Up @@ -73,8 +73,27 @@ internal class SentryDestination : Timber.Tree() {
wrapper?.extraInfo?.let { extras = it }
}

val hintWithAttachment = wrapper?.logAttachmentUrl?.let {logFile ->
Hint.withAttachment(Attachment(logFile.absolutePath))
// Iterate over the desired number of log files and add them as attachments.
val attachments = when (val numFiles = wrapper?.attachLogFiles ?: 0) {
0 -> null
else -> {
val attachments = mutableListOf<Attachment>()
// Sort by descending modified time so that we get the "latest" log files
SteamcLog.getAllLogFiles(LogSort.LastModifiedDesc)
?.take(numFiles)
?.forEach { file -> attachments += Attachment(file.absolutePath) }

// If we have successfully generated some Attachments, return them as an
// immutable list.
when (attachments.size) {
0 -> null
else -> attachments.toList()
}
}
}

val hintWithAttachment = attachments?.let { attachments ->
Hint.withAttachments(attachments)
}

Sentry.captureEvent(sentryEvent, hintWithAttachment)
Expand Down Expand Up @@ -124,19 +143,16 @@ internal class ConsoleDestination: Timber.DebugTree() {
super.log(priority, createCustomStackElementTag(), fullMessage, originalThrowable)
}
}

/**
* ExternalLogFileDestination == Disk
* DebugTree gives us access to override createStackElementTag
*/
internal class ExternalLogFileDestination : Timber.DebugTree() {
private var fileNamePrefix: String = "sclog"
private var fileExt = "txt"

private var rotatingIndexes = List(10) { it }

private var cachedCurrentLogFile: File? = null
private var currentLogFileCachedTime: Long? = null
private var currentLogFile: File? = null
private var currentLogFileEstimatedCreatedTime: Long? = null
private var logFileRotations = 10

override fun isLoggable(priority: Int): Boolean {
return isLoggable(SteamcLog.config.logLevel.disk, priority)
Expand Down Expand Up @@ -174,7 +190,7 @@ internal class ExternalLogFileDestination : Timber.DebugTree() {
*/
private fun printLogToExternalFile(message: String) {
try {
getExternalFile()?.let { file -> file.appendText("$message\r\n") }
getCurrentExternalFile()?.let { file -> file.appendText("$message\r\n") }
} catch (e: Exception) {
logToConsole("HTMLFileTree failed to write into file: $e")
}
Expand All @@ -186,11 +202,14 @@ internal class ExternalLogFileDestination : Timber.DebugTree() {
return logDirectory
}

fun getExternalFile(): File? {
/**
* Will get the external file we are currently writing to.
*/
private fun getCurrentExternalFile(): File? {
val expiryMs = SteamcLog.config.autoRotateConfig.fileRotationSeconds * 1000 // defaults to 10 minutes

if (isCachedLogFileValid(expiryMs)) {
return cachedCurrentLogFile
return currentLogFile
}

val currentFile = findAvailableLogFile(expiryMs)
Expand All @@ -201,23 +220,34 @@ internal class ExternalLogFileDestination : Timber.DebugTree() {
private fun isCachedLogFileValid(expiryMs: Long): Boolean {
// if you have a cached log file and you checked it within the expiry window
val now = Date().time
val currentLogFileCachedTime = currentLogFileCachedTime
return cachedCurrentLogFile != null &&
val currentLogFileCachedTime = currentLogFileEstimatedCreatedTime
return currentLogFileEstimatedCreatedTime != null &&
currentLogFileCachedTime != null &&
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

not sure I understand the logic behind this, you just assigned currentLogFileCachedTime = logFileCreatedTimeEstimate, so aren't we checking the same thing twice?

Copy link
Collaborator Author

@ssawchenko ssawchenko Aug 2, 2023

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This was done to avoid the IDE error:

Smart cast to 'Long' is impossible, because 'logFileCreatedTimeEstimate' is a mutable property that could have been changed by this time

I looked around online and it seemed like creating a local variable was a reasonable way to work around this: https://stackoverflow.com/questions/44595529/smart-cast-to-type-is-impossible-because-variable-is-a-mutable-property-tha

The return statement then makes sure that both the file and the estimated start time have been set (ie. aren't null) and then that that the file has not yet expired, so I don't think we're checking anything twice, but let me know if I'm missing something.

Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ah, I see.
What about doing it this way:

val currentLogFileCachedTime = logFileCreatedTimeEstimate ?: return false

I think that should ensure both the file and the estimated start time have been set, and then you should be able to remove both null checks

Copy link
Collaborator Author

@ssawchenko ssawchenko Aug 3, 2023

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Whoops I totally see the duplication! Also that's a good idea. Makes it much cleaner! Done :)

now - currentLogFileCachedTime < expiryMs
}

private fun updateCachedLogFile(file: File?) {
cachedCurrentLogFile = file
currentLogFileCachedTime = Date().time
// Only update if we are changing files; this helps us simulate when a file was "created" so
// that we can cycle every 10 mins
if (currentLogFile == file) { return }
Copy link
Collaborator Author

@ssawchenko ssawchenko Jul 28, 2023

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Before we were not checking for this, which was causing the currentLogFileCachedTime value to be incorrectly updated each time, meaning that the expiry calculation couldn't succeed as expected if the app was continually writing logs.


currentLogFile = file
currentLogFileEstimatedCreatedTime = Date().time
}

private fun findAvailableLogFile(expiryMs: Long): File? {
val now = Date().time
val possibleLogFiles = rotatingIndexes.map { index ->
val filename = "${fileNamePrefix}_${index}.${fileExt}"
File(getExternalLogDirectory(), filename)
}
val possibleLogFiles = List(logFileRotations) { it }
.map { index ->
val filename = "${fileNamePrefix}_${index}.${fileExt}"
File(getExternalLogDirectory(), filename)
}
.filter {
// Small hack: Filter out current log file from available list.
// It is possible that it's lastModified timestamp may cause the "expiry"
// check below to incorrectly flag the file as still available.
it.name != currentLogFile?.name
}

return try {
// attempt to find an empty file or one within the expiry window
Expand Down Expand Up @@ -253,10 +283,31 @@ internal class ExternalLogFileDestination : Timber.DebugTree() {
}
}

internal suspend fun getLogFileContents(): String? {
/**
* Returns the list of log files written to the log directory, sorted by the desired method.
*/
fun getLogFiles(sort: LogSort): List<File>? {
return when (sort) {
LogSort.LastModifiedAsc -> {
getExternalLogDirectory()?.listFiles()?.sortedBy { it.lastModified() }
}
LogSort.LastModifiedDesc -> {
getExternalLogDirectory()?.listFiles()?.sortedByDescending { it.lastModified() }
}
}
}

/**
* Returns the content of ALL log files strung together to form a single String.
* todo Given the size of the log files it may not be feasible to output this. This meathod
* was mostly used by the sample app to test out how the files are being split up.
*/
internal fun getLogFileContents(): String {
removeOldLogFiles()
val logBuilder = StringBuilder()
getExternalLogDirectory()?.listFiles()?.sortedBy { it.lastModified() }?.forEach { file ->
// Since log files sorted from oldest to newest, and logs contain entries from oldest to
// newest, we can cycle through and build up the FULL log from oldest to newest here.
getLogFiles(LogSort.LastModifiedAsc)?.forEach { file ->
try {
logToConsole("Reading file ${file.name}")
// This method is not recommended on huge files. It has an internal limitation of 2 GB file size.
Expand All @@ -270,10 +321,6 @@ internal class ExternalLogFileDestination : Timber.DebugTree() {

return logBuilder.toString()
}

internal fun deleteLogFile() {
getExternalFile()?.delete()
}
}

//-----------------------------------------------------------------------------
Expand Down
6 changes: 6 additions & 0 deletions steamclog/src/main/java/com/steamclock/steamclog/LogSort.kt
Original file line number Diff line number Diff line change
@@ -0,0 +1,6 @@
package com.steamclock.steamclog

enum class LogSort {
LastModifiedAsc,
LastModifiedDesc
}
Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We need to sort the logs in different orders in various places, so I made the setting explicit

20 changes: 8 additions & 12 deletions steamclog/src/main/java/com/steamclock/steamclog/Steamclog.kt
Original file line number Diff line number Diff line change
Expand Up @@ -103,12 +103,12 @@ object SteamcLog {
) {
val extraInfo = purpose?.let { config.extraInfo(purpose) }
val redactableObjectData = obj?.getRedactedDescription()
val logUrl = when (purpose == ExtraInfoPurpose.UserReport && config.detailedLogsOnUserReports) {
true -> externalLogFileTree.getExternalFile()
else -> null
val attachLogFiles = when (purpose == ExtraInfoPurpose.UserReport && config.detailedLogsOnUserReports) {
true -> 2 // Always attach 2 to cover case where we have recently cycled the log file
else -> 0
}

val wrapper = SteamclogThrowableWrapper(message, throwable, logUrl, redactableObjectData, extraInfo)
val wrapper = SteamclogThrowableWrapper(message, throwable, attachLogFiles, redactableObjectData, extraInfo)
Timber.log(logLevel.javaLevel, wrapper)
}

Expand Down Expand Up @@ -180,19 +180,15 @@ object SteamcLog {
* Log files may be spread out across multiple files; this method will join
* all log files into a single String.
*/
suspend fun getFullLogContents(): String? {
fun getFullLogContents(): String? {
return externalLogFileTree.getLogFileContents()
}

/**
* Returns the latest log file, based on the autoRotateConfig setting.
* Returns a list of ALL log files;
*/
fun getLastLogFile(): File? {
return externalLogFileTree.getExternalFile()
}

fun deleteLogFile() {
Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We don't actually support manual delete due to auto rotation; removing to avoid confusion

return externalLogFileTree.deleteLogFile()
fun getAllLogFiles(logSort: LogSort): List<File>? {
return externalLogFileTree.getLogFiles(logSort)
}

fun addCustomTree(tree: Timber.Tree) {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -11,7 +11,7 @@ import java.io.File
data class SteamclogThrowableWrapper(
val originalMessage: String,
val originalThrowable: Throwable?,
val logAttachmentUrl: File?,
val attachLogFiles: Int?,
val redactedObjectData: String?,
val extraInfo: Map<String, Any>?): Throwable(originalMessage)
{
Expand All @@ -22,7 +22,7 @@ data class SteamclogThrowableWrapper(
?: SteamclogThrowableWrapper(
throwable.message ?: throwable.toString(),
originalThrowable = throwable,
logAttachmentUrl = null,
attachLogFiles = 2,
redactedObjectData = null,
extraInfo = null
)
Expand Down