Parse logs and shorten UI output

4 files changed, 182 insertions, 12 deletions

diff --git a/ios/MullvadVPN.xcodeproj/project.pbxproj b/ios/MullvadVPN.xcodeproj/project.pbxproj
index 4161ef6378..f5516375e0 100644
--- a/ios/MullvadVPN.xcodeproj/project.pbxproj
+++ b/ios/MullvadVPN.xcodeproj/project.pbxproj
@@ -156,6 +156,7 @@
 		58C3A4B222456F1B00340BDB /* AccountInputGroupView.swift in Sources */ = {isa = PBXBuildFile; fileRef = 58C3A4B122456F1A00340BDB /* AccountInputGroupView.swift */; };
 		58C3B06724EA768100C0348E /* LogStreamerViewController.swift in Sources */ = {isa = PBXBuildFile; fileRef = 58C3B06624EA768100C0348E /* LogStreamerViewController.swift */; };
 		58C3B06924EAA25000C0348E /* StringStreamIterator.swift in Sources */ = {isa = PBXBuildFile; fileRef = 58C3B06824EAA25000C0348E /* StringStreamIterator.swift */; };
+		58C4CB0124EBE5A700A22D49 /* LogEntryParser.swift in Sources */ = {isa = PBXBuildFile; fileRef = 58C4CB0024EBE5A700A22D49 /* LogEntryParser.swift */; };
 		58C6B34F22BB7AC0003C19AD /* IPAddressRange.swift in Sources */ = {isa = PBXBuildFile; fileRef = 58C6B34E22BB7AC0003C19AD /* IPAddressRange.swift */; };
 		58C6B35122BB7CFD003C19AD /* IPAddressRange.swift in Sources */ = {isa = PBXBuildFile; fileRef = 58C6B34E22BB7AC0003C19AD /* IPAddressRange.swift */; };
 		58C6B35422BB87C4003C19AD /* WireguardPrivateKey.swift in Sources */ = {isa = PBXBuildFile; fileRef = 58C6B35322BB87C4003C19AD /* WireguardPrivateKey.swift */; };
@@ -343,6 +344,7 @@
 		58C3A4B122456F1A00340BDB /* AccountInputGroupView.swift */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.swift; path = AccountInputGroupView.swift; sourceTree = "<group>"; };
 		58C3B06624EA768100C0348E /* LogStreamerViewController.swift */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.swift; path = LogStreamerViewController.swift; sourceTree = "<group>"; };
 		58C3B06824EAA25000C0348E /* StringStreamIterator.swift */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.swift; path = StringStreamIterator.swift; sourceTree = "<group>"; };
+		58C4CB0024EBE5A700A22D49 /* LogEntryParser.swift */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.swift; path = LogEntryParser.swift; sourceTree = "<group>"; };
 		58C6B34E22BB7AC0003C19AD /* IPAddressRange.swift */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.swift; path = IPAddressRange.swift; sourceTree = "<group>"; };
 		58C6B35322BB87C4003C19AD /* WireguardPrivateKey.swift */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.swift; path = WireguardPrivateKey.swift; sourceTree = "<group>"; };
 		58C6B35D22BBBFE3003C19AD /* Data+HexCoding.swift */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.swift; path = "Data+HexCoding.swift"; sourceTree = "<group>"; };
@@ -470,6 +472,7 @@
 			children = (
 				581503A224D6F1EC00C9C50E /* ChainedError+Logger.swift */,
 				5815039624D6ECAE00C9C50E /* CustomFormatLogHandler.swift */,
+				58C4CB0024EBE5A700A22D49 /* LogEntryParser.swift */,
 				581503A524D6F4AE00C9C50E /* Logging.swift */,
 				5815039324D6EB7200C9C50E /* LogRotation.swift */,
 				585FE2F024E1365400439C50 /* LogStreamer.swift */,
@@ -1049,6 +1052,7 @@
 				5811DE50239014550011EB53 /* NEVPNStatus+Debug.swift in Sources */,
 				58141EC924DAC0ED0013F79C /* TextFileStream.swift in Sources */,
 				58C3A4B222456F1B00340BDB /* AccountInputGroupView.swift in Sources */,
+				58C4CB0124EBE5A700A22D49 /* LogEntryParser.swift in Sources */,
 				58F840B22464491D0044E708 /* ChainedError.swift in Sources */,
 				58FAEDFF24533A7000CB0F5B /* KeychainReturn.swift in Sources */,
 				580EE20C24B3225F00F9D8A1 /* DelayOperation.swift in Sources */,
diff --git a/ios/MullvadVPN/LogStreamerViewController.swift b/ios/MullvadVPN/LogStreamerViewController.swift
index 4052da4dba..d033a8fc70 100644
--- a/ios/MullvadVPN/LogStreamerViewController.swift
+++ b/ios/MullvadVPN/LogStreamerViewController.swift
@@ -10,11 +10,19 @@
 
 import Foundation
 import UIKit
+import Logging
 
 class LogStreamerViewController: UIViewController, UITextViewDelegate {
 
     private let textView = UITextView()
     private let streamer: LogStreamer<UTF8>
+    private let logEntryParser = LogEntryParser()
+    private var currentTextColor: UIColor?
+    private let timestampFormatter: DateFormatter = {
+        let formatter = DateFormatter()
+        formatter.dateFormat = "HH:mm:ss.SSS"
+        return formatter
+    }()
 
     private var autoScrollButtonItem: UIBarButtonItem {
         return UIBarButtonItem(barButtonSystemItem: autoScroll ? .pause : .play, target: self, action: #selector(handleToggleAutoscroll(_:)))
@@ -75,6 +83,11 @@ class LogStreamerViewController: UIViewController, UITextViewDelegate {
     private func addSubviews() {
         textView.translatesAutoresizingMaskIntoConstraints = false
         textView.isEditable = false
+        if #available(iOS 13.0, *) {
+            textView.font = UIFont.monospacedSystemFont(ofSize: UIFont.systemFontSize, weight: .regular)
+        } else {
+            textView.font = UIFont(name: "Courier", size: UIFont.systemFontSize)
+        }
         textView.delegate = self
 
         view.addSubview(textView)
@@ -92,14 +105,42 @@ class LogStreamerViewController: UIViewController, UITextViewDelegate {
             guard let self = self else { return }
 
             DispatchQueue.main.async {
-                self.textView.insertText("\(str)\n")
+                // Try parsing the entry
+                let entry = self.logEntryParser.parse(str)
+
+                // Since the log streamer sends the log file line-by-line, it's possible that only a
+                // part of a multiline message is captured at first.
+                let message = entry.map { (entry) -> String in
+                    // Reformat the log entry date
+                    let timestamp = self.timestampFormatter.string(from: entry.timestamp)
+
+                    return "\(timestamp) \(entry.module) \(entry.message)\n"
+                } ?? "\(str)\n"
+
+
+                // Compute the range for replacing the text color
+                let start = self.textView.text.utf16.count
+                let end = start + message.utf16.count
+                let textRange = NSRange(start..<end)
+
+                self.textView.insertText(message)
                 self.handleAutoScroll()
+
+                // Update the current log entry color
+                if let logLevel = entry?.level {
+                    self.currentTextColor = self.textColor(for: logLevel)
+                }
+
+                // Apply the color attribute to the inserted text
+                if let textColor = self.currentTextColor {
+                    self.textView.textStorage.addAttributes([.foregroundColor: textColor], range: textRange)
+                }
             }
         }
     }
 
     private func handleAutoScroll() {
-        if autoScroll && !textView.isTracking && !textView.isDragging {
+        if autoScroll && !textView.isTracking && (!textView.isDragging || textView.isDecelerating) {
             scrollToBottom()
         }
     }
@@ -114,6 +155,19 @@ class LogStreamerViewController: UIViewController, UITextViewDelegate {
         navigationItem.leftBarButtonItem = autoScrollButtonItem
     }
 
+    private func textColor(for logLevel: Logger.Level) -> UIColor {
+        switch logLevel {
+        case .debug, .trace:
+            return .lightGray
+        case .error, .critical:
+            return .red
+        case .info, .notice:
+            return .blue
+        case .warning:
+            return .orange
+        }
+    }
+
     // MARK: - Actions
 
     @objc func handleDismissButton(_ sender: Any) {
diff --git a/ios/MullvadVPN/Logging/LogEntryParser.swift b/ios/MullvadVPN/Logging/LogEntryParser.swift
new file mode 100644
index 0000000000..c7b3a68db7
--- /dev/null
+++ b/ios/MullvadVPN/Logging/LogEntryParser.swift
@@ -0,0 +1,98 @@
+//
+//  LogEntryParser.swift
+//  MullvadVPN
+//
+//  Created by pronebird on 18/08/2020.
+//  Copyright © 2020 Mullvad VPN AB. All rights reserved.
+//
+
+#if DEBUG
+
+import Foundation
+import Logging
+
+struct ParsedLogEntry {
+    let timestamp: Date
+    let level: Logger.Level
+    let module: String
+    let message: String
+}
+
+class LogEntryParser {
+    /// Date formatter used for decoding the timestamp
+    private let dateFormatter = CustomFormatLogHandler.makeDateFormatter()
+
+    /// Parse a log entry in the following format:
+    /// [<DATE>][<MODULE>][<LOG_LEVEL>] <MESSAGE>
+    func parse(_ str: String) -> ParsedLogEntry? {
+        let ranges = Self.stringRangesWithinSquareBrackets(string: str, maxResults: 3)
+        guard ranges.count == 3 else {
+            return nil
+        }
+
+        let strings = ranges.map { String(str[$0]) }
+
+        guard let timestamp = dateFormatter.date(from: strings[0]),
+            let logLevel = Logger.Level(rawValue: strings[2]) else {
+                return nil
+        }
+
+        // Extract the log message following the log level
+        let startIndex = str.index(ranges.last!.upperBound, offsetBy: 1, limitedBy: str.endIndex)
+        let message = startIndex.map({ (startIndex) -> String in
+            return str[startIndex..<str.endIndex].trimmingCharacters(in: .whitespaces)
+        }) ?? ""
+
+        return ParsedLogEntry(
+            timestamp: timestamp,
+            level: logLevel,
+            module: strings[1],
+            message: message
+        )
+    }
+
+    /// Find consecutive ranges of strings within square brackets.
+    private static func stringRangesWithinSquareBrackets(string: String, maxResults: Int) -> [Range<String.Index>] {
+        var results = [Range<String.Index>]()
+        var maybeStartIndex: String.Index?
+
+        guard maxResults > 0 else { return results }
+
+        loop: for (offset, char) in string.enumerated() {
+            switch char {
+            case "[":
+                if maybeStartIndex == nil {
+                    maybeStartIndex = string.index(string.startIndex, offsetBy: offset + 1, limitedBy: string.endIndex)
+                } else {
+                    // out of order
+                    break loop
+                }
+
+            case "]":
+                if let startIndex = maybeStartIndex {
+                    maybeStartIndex = nil
+
+                    let endIndex = string.index(string.startIndex, offsetBy: offset)
+
+                    results.append((startIndex..<endIndex))
+
+                    if results.count >= maxResults {
+                        // done
+                        break loop
+                    }
+                } else {
+                    // out of order
+                    break loop
+                }
+
+            default:
+                continue
+            }
+        }
+
+        return results
+    }
+
+}
+
+#endif
diff --git a/ios/MullvadVPN/Logging/LogStreamer.swift b/ios/MullvadVPN/Logging/LogStreamer.swift
index bd4583e8ce..23da9fae31 100644
--- a/ios/MullvadVPN/Logging/LogStreamer.swift
+++ b/ios/MullvadVPN/Logging/LogStreamer.swift
@@ -15,7 +15,7 @@ private let kLogPollIntervalSeconds = 2
 /// A class that consolidates multiple log streams into one
 class LogStreamer<Codec> where Codec: UnicodeCodec {
     private let fileURLs: [URL]
-    private var remainingFileURLs: [URL]
+    private var pendingFileURLs: [URL]
     private var streams = [TextFileStream<Codec>]()
     private var eventSources = [DispatchSourceFileSystemObject]()
     private let queue = DispatchQueue(label: "net.mullvad.MullvadVPN.LogStreamer<\(Codec.self)>")
@@ -25,7 +25,11 @@ class LogStreamer<Codec> where Codec: UnicodeCodec {
 
     init(fileURLs: [URL]) {
         self.fileURLs = fileURLs
-        self.remainingFileURLs = fileURLs
+        self.pendingFileURLs = fileURLs
+    }
+
+    deinit {
+        cancelAndRemoveAllEventSources()
     }
 
     func start(handler: @escaping (String) -> Void) {
@@ -47,15 +51,15 @@ class LogStreamer<Codec> where Codec: UnicodeCodec {
             self.retry?.cancel()
             self.handlerBlock = nil
 
-            self.eventSources.removeAll()
+            self.cancelAndRemoveAllEventSources()
             self.streams.removeAll()
-            self.remainingFileURLs = self.fileURLs
+            self.pendingFileURLs = self.fileURLs
         }
     }
 
     private func openRemainingStreams() -> Bool {
         var failedURLs = [URL]()
-        for fileURL in remainingFileURLs {
+        for fileURL in pendingFileURLs {
             if let stream = TextFileStream<Codec>(fileURL: fileURL, separator: "\n") {
                 streams.append(stream)
 
@@ -73,7 +77,7 @@ class LogStreamer<Codec> where Codec: UnicodeCodec {
             }
         }
 
-        remainingFileURLs = failedURLs
+        pendingFileURLs = failedURLs
 
         return failedURLs.isEmpty
     }
@@ -103,18 +107,23 @@ class LogStreamer<Codec> where Codec: UnicodeCodec {
         )
 
         source.setEventHandler { [weak self, weak source] in
-            guard let self = self, self.isStarted else { return }
+            guard let self = self, let source = source, self.isStarted else { return }
 
             // Cancel current event source
-            source?.cancel()
+            source.cancel()
 
             // Release the stream
             self.streams.removeAll { (s) -> Bool in
                 return stream === s
             }
 
-            // Add the file URL to backlog & poll
-            self.remainingFileURLs.append(fileURL)
+            // Release the current event source
+            self.eventSources.removeAll { (s) -> Bool in
+                return source === s
+            }
+
+            // Add the file URL to backlog & start polling
+            self.pendingFileURLs.append(fileURL)
             self.poll()
         }
 
@@ -122,6 +131,11 @@ class LogStreamer<Codec> where Codec: UnicodeCodec {
 
         eventSources.append(source)
     }
+
+    private func cancelAndRemoveAllEventSources() {
+        eventSources.forEach { $0.cancel() }
+        eventSources.removeAll()
+    }
 }
 
 #endif