Cocoalumberjack: Unarchived log file is not rolled and archived after application is restarted and manually rolling also does not work.

[imran20487]

New Issue Checklist

• [y ] I have read and understood the CONTRIBUTING guide
• [ y] I have read the Documentation or CocoaDocs
• [ y] I have searched for a similar issue in the project and found none

Issue Info

Info | Value |
-------------------------|-------------------------------------|
Platform Name | osx
Platform Version | 10.15
CocoaLumberjack Version | 3.6.2
Integration Method | Swift Package
Xcode Version | Xcode 11.6
Repro rate | all the time (100%)
Demo project link | e.g. link to a demo project that highlights the issue

Issue Description and Steps

Unarchived log file is not rolled back after application is restarted and manually rolling also does not work.
Here is the code setup I have

let fileManager = MyLogFileManager()
let fileLogger = DDFileLogger(logFileManager: fileManager)
fileLogger.logFormatter = MyFormatter()
fileLogger.automaticallyAppendNewlineForCustomFormatters = true
fileLogger.rollingFrequency = 300//5 minutes
fileLogger.maximumFileSize = 51200
fileLogger.logFileManager.maximumNumberOfLogFiles = 1
DDLog.add(fileLogger, with: myLevel)

Steps:
1) Log to file using DDLog(message, mylevel)
I can see the log file being created with the proper timestamp
2) Quit the application before the file is rolled and archived, I can see the log file is still there.
3) Restart the App, check for DDLogFileInfo.isArchived which returns false correctly. But it never gets rolled, even after calling fileLogger.rollLogFileWithCompletionBlock

Wanted to know if such feature exists in the framework where it could automatically roll the file upon restart and if not how can I manually do it?

[ffried]

@imran20487 Could you provide the values for config.batchFileRollingFrequencyInSec and config.maxBatchFileSizeInBytes as well as the implementation of MyLogFileManager?
Does this also happen with the DDDefaultLogFileManager?

[imran20487]

@imran20487 Could you provide the values for config.batchFileRollingFrequencyInSec and config.maxBatchFileSizeInBytes as well as the implementation of MyLogFileManager?
Does this also happen with the DDDefaultLogFileManager?

@ffried rollingFrequency = 500 and maximumFileSize = 51200. Actually in this case it does not matter what these values are, even with a very small values, the issue still occurs.

MyLogFileManager has only a single overriding function didRollAndArchiveLogFile in which it sends the log to the backend .
I see the same issue with DDDefaultLogFileManager also.

After the App restarts, I don't see didRollAndArchiveLogFile getting called on the file which was not rolled before quitting.
Some more info:
After the App restarts, I do DDLog(message, myLevel) which logs to a new file and now the framework deletes (since maximumNumberOfLogFiles = 1) the old file but without calling didRollAndArchiveLogFile on the LogFileManager.
I think that it assumes that the old file is already rolled before creating a new one.

[ffried]

@imran20487 I see now! The behavior is actually correct. You tell the log file manager to only keep one file around. Thus the old file will never be archived, but deleted directly instead whenever a new log file is created. See here.
Whenever it is rolled, however, it _is_ archived (just before being deleted), but that's a different case.

You probably want to set doNotReuseLogFiles to true on your file logger. This will make sure that CocoaLumberjack does not reuse old log files. In this case the old one is archived (including notifying the manager) before a new one is created (and in your case the old one deleted).

Also, while not strictly necessary, I'd recommend setting maximumNumberOfLogFiles to 2, so that you are able to re-upload a log file e.g. in case of failure. Your mileage may vary, but in most cases keeping one additional log file around shouldn't be a problem. You could still delete the old log file once you've uploaded it. CocoaLumberjack shouldn't care about _archived_ log files being deleted.

[imran20487]

@ffried As per your suggestion I have set doNotReuseLogFiles = true and maximumNumberOfLogFiles = 2.
I see the same behaviour that the log file which was not rolled and archived before App quitting never gets rolled but gets archived after application is re-started when continued with logging.

Here is the sequence of events and the behaviour with the log files:

Initially logged several messages and waited so as to make both the logs get rolled and archived
1.log - rolled and archived
2.log - rolled and archived
DDLog(message, myLevel)
1.log - deleted
2.log - rolled and archived
3.log - newly created (file that I am interested in)
Quit the application
Re-start the application
2.log - rolled and archived
3.log - not rolled and not archived (DDLogFileInfo.isArchived returns false for this file)
DDLog(message2, myLevel)
2.log - deleted
3.log - archived without rolling (FileManager is not notified)
4.log - newly created
DDLog(message3, myLevel)
3.log - deleted without rolling
4.log - rolled and archived
5.log - newly created

Is there a way to manually roll and archive or the framework needs modifications?

[ffried]

@imran20487 That however doesn't sound right... 🤔

Would it be possible for you to provide a small sample project which reproduces the behavior? That would make debugging a lot easier.
If not, could you override createNewLogFile (or createNewLogFileWithError: in ObjC) in your file manager and attach the stack trace for the line 3.log - archived without rolling (FileManager is not notified) in your list above?
Since this method is the only place that creates new files, this should definitively happen for 4.log - newly created.

[ffried]

@imran20487 Another quick question: you only mentioned didRollAndArchiveLogFile:... Are you also implementing didArchiveLogFile:?
The former is only called if the log file is really _rolled_ - that is when one of the rolling conditions apply (size, age or manual rolling).
The latter is called when the file logger archives the log file "at startup", e.g. when doNotReuseLogFiles is set to true.

[imran20487]

@ffried have implemented only didRollAndArchiveLogFile.
I will try to provide a sample project for you or the stack trace whichever helps.

[imran20487]

@ffried A quick update, I have now overridden the didArchiveLogFile function and it gets notified on 4.log - newly created and I don't see didRollAndArchiveLogFile notified.

[ffried]

@imran20487 Ok, thanks! Then there's at least no bug here. That behavior is correct, as I stated earlier. Nevertheless I'm preparing a PR that migrates the two methods into one, which includes a bool parameter that specifies whether or not the log file was archived after rolling.

[imran20487]

@ffried So for now, should I be uploading /take any action on that file in didArchiveLogFile also, same as what I am doing in didRollAndArchiveLogFile?

[ffried]

@imran20487 Yep. While merging the two methods, I've found that our demo and test implementations did exactly that. See CompressingLogFileManager (Demo) and DDSampleLogFileManager (Tests)...

[ffried]

@imran20487 I'm closing this issue now, since the current behavior, while somewhat hard to reason about, is technically correct. If you still encounter any issues, please feel free to re-open it.

[imran20487]

@ffried Thanks for your inputs, so the #1166 would be in release 3.6.3?

We can close this issue.

[ffried]

@imran20487 #1166 will very likely be in 3.7.0 (planned to be released somewhat around the release of Xcode 12). Since it's technically not a bug, I don't think it'll require a bugfix release.