Ensure log file sizes stay below a certain threshold

[rablador]

We should limit log files to not be larger than a certain threshold (currently 16kB) when writing to disk. If limit is exceeded, create a new file with a "_" suffix and keep writing to it instead. Repeat if necessary.

---

This change is 

[linear]

IOS-635 Ensure log file sizes stay below a certain threshold

[rablador]

Will look at creating tests shortly.

Reviewable status: 0 of 13 files reviewed, all discussions resolved

[mojganii]

Reviewable status: 0 of 13 files reviewed, 3 unresolved discussions (waiting on @rablador)

---

ios/MullvadLogging/Date+LogFormat.swift line 13 at r1 (raw file):

extension Date {
    public var logFormatted: String {
        logFileFormatted.replacingOccurrences(of: "T", with: " ")

we are doing some string manipulation in Date extension that has nothing to do with that.Moreover, the using formatter is much more sensible to me instead of replacing.

Code snippet:

let formatter = DateFormatter()
formatter.dateFormat = "dd/MM/yyyy HH:mm:ss"
return formatter.string(from: self)

---

ios/MullvadLogging/LogFileOutputStream.swift line 101 at r1 (raw file):

        guard partialFileSizeCounter <= ApplicationConfiguration.logMaximumFileSize else {
            try fileHandle.close()

nit : for having more readability I suggest to put this scope of the file in another function which is called writeInNewFile or something like that

---

ios/MullvadLogging/LogFileOutputStream.swift line 196 at r1 (raw file):

    }

    private func incrementFileName(partialFileCounter: Int) throws -> URL {

we have the partialFileCounter as a global value, there is no need to pass it to function. the name of functions doesn't make sense the return value is a file url for new file.

Code snippet:

    private func newFileUrl() throws -> URL {
        if let url = URL(string: baseFileURL.relativePath + "_\(self.partialFileNameCounter).log") {
            return url
        } else {
            throw POSIXError(POSIXErrorCode(rawValue: 2)!) // "No such file or directory"
        }
    }

[rablador]

Reviewable status: 0 of 13 files reviewed, 2 unresolved discussions (waiting on @mojganii)

---

ios/MullvadLogging/Date+LogFormat.swift line 13 at r1 (raw file):

Previously, mojganii wrote…

we are doing some string manipulation in Date extension that has nothing to do with that.Moreover, the using formatter is much more sensible to me instead of replacing.

Alright, I'll revert the change and apply locale and timezone instead.

---

ios/MullvadLogging/LogFileOutputStream.swift line 101 at r1 (raw file):

Previously, mojganii wrote…

nit : for having more readability I suggest to put this scope of the file in another function which is called writeInNewFile or something like that

Done.

---

ios/MullvadLogging/LogFileOutputStream.swift line 196 at r1 (raw file):

Previously, mojganii wrote…

we have the partialFileCounter as a global value, there is no need to pass it to function. the name of functions doesn't make sense the return value is a file url for new file.

Done.

[rablador]

Reviewable status: 0 of 16 files reviewed, 3 unresolved discussions (waiting on @mojganii)

---

ios/MullvadLogging/LogFileOutputStream.swift line 109 at r2 (raw file):

        // Rotate file if threshold has been met, then rerun the write operation.
        guard partialFileSizeCounter <= fileSizeLimit else {

There is a caveat here. If the incoming data chunks themselves are larger than fileSizeLimit, no logs will be written at all. AND many many new log files will be created.

[buggmagnet]

Reviewed 11 of 13 files at r1, 4 of 5 files at r2, all commit messages.
Reviewable status: 15 of 16 files reviewed, 11 unresolved discussions (waiting on @mojganii and @rablador)

---

ios/MullvadLogging/LogFileOutputStream.swift line 106 at r2 (raw file):

    private func write(fileHandle: FileHandle, data: Data) throws {
        partialFileSizeCounter += UInt64(data.count)

This isn't correct.
We should only increase the partialFileSizeCounter with the number of bytes written (returned by Darwin.write)

Otherwise, we'll have a mismatch when we fail to write below.

---

ios/MullvadLogging/LogFileOutputStream.swift line 118 at r2 (raw file):

            guard let ptr = buffer.baseAddress else { return 0 }

            return Darwin.write(fileHandle.fileDescriptor, ptr, buffer.count)

nit
The small downside of this is that we can't easily test scenarios where we have to bufferData
Fortunately, the data we buffer is way lower than a maximum file size, so we shouldn't have any scenario where we end up
in a loop where we can't write to a new file because there is too much buffered data.

---

ios/MullvadLogging/LogFileOutputStream.swift line 127 at r2 (raw file):

    }

    fileprivate func rotateFile(handle: FileHandle, data: Data) throws {

That data parameter is not used

---

ios/MullvadLogging/LogFileOutputStream.swift line 213 at r2 (raw file):

            return url
        } else {
            throw POSIXError(POSIXErrorCode(rawValue: 2)!) // "No such file or directory"

throw POSIXError(.ENOENT)

---

ios/MullvadVPN.xcodeproj/project.pbxproj line 6504 at r2 (raw file):

				PRODUCT_NAME = "$(TARGET_NAME)";
				SWIFT_OPTIMIZATION_LEVEL = "-Onone";
				SWIFT_STRICT_CONCURRENCY = minimal;

Did you mean to check this in ?

---

ios/MullvadVPNTests/LoggingTests.swift line 37 at r2 (raw file):

        sync()

        let contents = String(decoding: (try? Data(contentsOf: fileURL)) ?? Data(), as: UTF8.self)

let contents = try XCTUnwrap(String(contentsOf: fileURL)) is much easier to read (we also need to mark the test as throws
Same for the test below

---

ios/MullvadVPNTests/LogRotationTests.swift line 35 at r2 (raw file):

        let logChunkSize = 20

        let exptectedLogCount = Int(ceil(Double(totalLogTestSize) / Double(totalLogSizeLimit)))

exptectedLogCount -> expectedLogCount

---

ios/MullvadVPNTests/LogRotationTests.swift line 138 at r2 (raw file):

extension LogRotationTests {
    private func stringOfSize(_ size: Int) -> String {
        String(repeating: " ", count: size)

nit
if you look at the files generated during the tests, it just looks like empty space, that's quite fun !
But it's not a big deal

[rablador]

Reviewable status: 15 of 16 files reviewed, 11 unresolved discussions (waiting on @buggmagnet and @mojganii)

---

ios/MullvadLogging/LogFileOutputStream.swift line 106 at r2 (raw file):

Previously, buggmagnet wrote…

This isn't correct.
We should only increase the partialFileSizeCounter with the number of bytes written (returned by Darwin.write)

Otherwise, we'll have a mismatch when we fail to write below.

You're right, I moved the counter to the bottom. We should, however, still check for size limitation before attempting to write, so introduced a temporary prediction for that instead.

---

ios/MullvadLogging/LogFileOutputStream.swift line 118 at r2 (raw file):

Previously, buggmagnet wrote…

nit
The small downside of this is that we can't easily test scenarios where we have to bufferData
Fortunately, the data we buffer is way lower than a maximum file size, so we shouldn't have any scenario where we end up
in a loop where we can't write to a new file because there is too much buffered data.

Yes, in realty this should not be a problem, but it still feels iffy that we could end up with in a bad state if not configured properly.

---

ios/MullvadLogging/LogFileOutputStream.swift line 127 at r2 (raw file):

Previously, buggmagnet wrote…

That data parameter is not used

Done.

---

ios/MullvadLogging/LogFileOutputStream.swift line 213 at r2 (raw file):

Previously, buggmagnet wrote…

throw POSIXError(.ENOENT)

That's what I wanted, yes :)

---

ios/MullvadVPN.xcodeproj/project.pbxproj line 6504 at r2 (raw file):

Previously, buggmagnet wrote…

Did you mean to check this in ?

Nope...

---

ios/MullvadVPNTests/LoggingTests.swift line 37 at r2 (raw file):

Previously, buggmagnet wrote…

let contents = try XCTUnwrap(String(contentsOf: fileURL)) is much easier to read (we also need to mark the test as throws
Same for the test below

Didn't want to intrude too much on the existing code, just fix the lint error. But let's change it now that it's been pointed out.

---

ios/MullvadVPNTests/LogRotationTests.swift line 35 at r2 (raw file):

Previously, buggmagnet wrote…

exptectedLogCount -> expectedLogCount

Done.

---

ios/MullvadVPNTests/LogRotationTests.swift line 138 at r2 (raw file):

Previously, buggmagnet wrote…

nit
if you look at the files generated during the tests, it just looks like empty space, that's quite fun !
But it's not a big deal

Felt like the most secure way to generate one byte per character. But I guess I could go with an "a" or something.

[mojganii]

Reviewable status: 12 of 16 files reviewed, 10 unresolved discussions (waiting on @buggmagnet and @rablador)

---

ios/MullvadLogging/LogFileOutputStream.swift line 109 at r2 (raw file):

Previously, rablador (Jon Petersson) wrote…

There is a caveat here. If the incoming data chunks themselves are larger than fileSizeLimit, no logs will be written at all. AND many many new log files will be created.

Can't we truncate the incoming data into different smaller chunks and write them in different files throughs a loop if the data size is bigger the limit?

Code snippet:

    fileprivate func rotateFile(handle: FileHandle, data: Data) throws {
        var limit = fileSizeLimit
        var offset: UInt64 = 0

        let size = UInt64(data.count)

        while offset < data.count {
            try handle.close()
            state = .closed
            fileURL = try incrementFileName()
            limit = offset + limit < size ? limit : (size - offset)
            write(String(data: data[Data.Index(offset) ..< Data.Index(offset + limit)], encoding: encoding) ?? "")
            offset += limit
        }

        partialFileSizeCounter = 0
    }

[acb-mv]

Reviewed 1 of 5 files at r2, 2 of 4 files at r3, 2 of 2 files at r4, all commit messages.
Reviewable status: all files reviewed, 10 unresolved discussions (waiting on @buggmagnet, @mojganii, and @rablador)

---

ios/MullvadVPNTests/LogRotationTests.swift line 138 at r2 (raw file):

Previously, rablador (Jon Petersson) wrote…

Felt like the most secure way to generate one byte per character. But I guess I could go with an "a" or something.

If you want a sequence that's less featureless, you could do something like

(0..<size).map { "\($0%10)" }.joined(separator: '')

which gives you 0123456789012..., or something similar.

[rablador]

Reviewable status: all files reviewed, 10 unresolved discussions (waiting on @acb-mv, @buggmagnet, and @mojganii)

---

ios/MullvadLogging/LogFileOutputStream.swift line 109 at r2 (raw file):

Previously, mojganii wrote…

Can't we truncate the incoming data into different smaller chunks and write them in different files throughs a loop if the data size is bigger the limit?

write() calls to an async queue, so the while loop here gets interweaved with calls from the re-queued items as well as the current item being processed. Perhaps we can do something of similar logic though. What do @acb-mv or @buggmagnet think? Worth the extra effort?

---

ios/MullvadVPNTests/LogRotationTests.swift line 138 at r2 (raw file):

Previously, acb-mv wrote…

If you want a sequence that's less featureless, you could do something like

(0..<size).map { "\($0%10)" }.joined(separator: '')

which gives you 0123456789012..., or something similar.

I like it 👍

[buggmagnet]

Reviewed 1 of 4 files at r3, 1 of 2 files at r4, 1 of 1 files at r5, all commit messages.
Reviewable status: all files reviewed, 5 unresolved discussions (waiting on @acb-mv, @mojganii, and @rablador)

---

ios/MullvadLogging/LogFileOutputStream.swift line 109 at r2 (raw file):

If the incoming data chunks themselves are larger than fileSizeLimit, no logs will be written at all. AND many many new log files will be created.

You are technically correct, but it's not a realistic problem to solve IMHO, 128k data to write is a truckload of data, especially given that we control most of the data written to the log files.

I would say in that case, throw an error and drop all the data. We shouldn't make this more complicated than it already is.

---

ios/MullvadLogging/LogFileOutputStream.swift line 78 at r5 (raw file):

    }

    private func writeNoQueue(_ string: String) {

nit
Everytime I read this method name, I'm confused because it's only ever called from the dispatch queue we have here.
Can we rename this writeOnQueue instead ?

Also we should sprinkle some dispatchPrecondition(condition: .onQueue(queue)) in every function that is called on the queue to help get more contextual information as to what happens where IMHO

---

ios/MullvadVPN.xcodeproj/project.pbxproj line 6539 at r5 (raw file):

				PRODUCT_BUNDLE_IDENTIFIER = "$(APPLICATION_IDENTIFIER)";
				PRODUCT_NAME = "$(TARGET_NAME)";
				SUPPORTED_PLATFORMS = "iphoneos iphonesimulator";

What about these changes, did you mean to check them in ?

[rablador]

Reviewable status: all files reviewed, 4 unresolved discussions (waiting on @buggmagnet and @mojganii)

---

ios/MullvadLogging/LogFileOutputStream.swift line 109 at r2 (raw file):

Previously, buggmagnet wrote…

If the incoming data chunks themselves are larger than fileSizeLimit, no logs will be written at all. AND many many new log files will be created.

You are technically correct, but it's not a realistic problem to solve IMHO, 128k data to write is a truckload of data, especially given that we control most of the data written to the log files.

I would say in that case, throw an error and drop all the data. We shouldn't make this more complicated than it already is.

I think you're right. If we throw an error, the data will be buffered (and trimmed), thus solving the immediate problem of chunk size being too large. It doesn't really fix anything, but it handles deviations gracefully, which is good enough I think.

---

ios/MullvadLogging/LogFileOutputStream.swift line 78 at r5 (raw file):

Previously, buggmagnet wrote…

nit
Everytime I read this method name, I'm confused because it's only ever called from the dispatch queue we have here.
Can we rename this writeOnQueue instead ?

Also we should sprinkle some dispatchPrecondition(condition: .onQueue(queue)) in every function that is called on the queue to help get more contextual information as to what happens where IMHO

Added a dispatchPrecondition to write(fileHandle: FileHandle, data: Data) since that's were the actual writing happens. We can end up there either directly from a function call or indirectly from a timer call.

---

ios/MullvadVPN.xcodeproj/project.pbxproj line 6539 at r5 (raw file):

Previously, buggmagnet wrote…

What about these changes, did you mean to check them in ?

The changes you see are probably between revisions where I either messed up or restored the mess. If you compare first and last revision there will be no changes here.

[buggmagnet]

Reviewed 6 of 6 files at r6, all commit messages.
Reviewable status: all files reviewed, 1 unresolved discussion (waiting on @mojganii)