Implemented Logging for parsing arguments. (#2)

* added logger and some log statements.

* excluding .build dir for linting.

* added test with logging

* fixed lint errors

* fixed code formatting.

* fixed formatting

.swiftlint.yml

@@ -4,3 +4,5 @@ disabled_rules: # rule identifiers to exclude from running
   - force_try
 function_body_length:
   - 100
+excluded:
+  - .build

Package.swift

@@ -12,17 +12,22 @@ let package = Package(
             ]),
     ],
     dependencies: [
+        .package(url: "https://github.com/IBM-Swift/LoggerAPI.git", from: "1.7.0"),
+        .package(url: "https://github.com/IBM-Swift/HeliumLogger.git", from: "1.7.0")
     ],
     targets: [
         .target(
             name: "argtree",
-            dependencies: [],
+            dependencies: [
+                "LoggerAPI",
+            ],
             path: "Sources"
         ),
         .testTarget(
             name: "argtreeTests",
             dependencies: [
                 "argtree",
+                "HeliumLogger",
             ]),
     ]
 )

README.md

@@ -528,8 +528,18 @@ do {
 To get a deeper understanding of why a certain argument is parsed or not parsed it can be very helpful to switch 
 on logging.
 
-(not implemented yet)
-TODO
+Logging is done via the [LoggerAPI](https://github.com/IBM-Swift/LoggerAPI). So by default nothing is logged. 
+To activate logging, one must configure a logger. A simple logger is e.g. 
+[HeliumLogger](https://github.com/IBM-Swift/HeliumLogger) which can be employed in the following way.
+```swift
+import LoggerAPI
+import HeliumLogger
+Log.log = HeliumLogger(.debug)
+
+let argTree = ArgTree()
+try! argtree.parse()
+```
+Note that most of the logging is done on debug level, so this level should be activated to see any log output.
 
 ## Architecture
 TODO

Sources/ArgTree.swift

@@ -4,6 +4,8 @@ import Darwin
 import Glibc
 #endif
 
+import LoggerAPI
+
 /**
  * A parse path segment can be used to form a parse path
  */
@@ -90,6 +92,7 @@ public class ArgTree: ParserNode {
             helpPrinted()
         }
         // add help as first parse, to play together with the var arg parser
+        Log.debug("creating generated help flag as first parser")
         insert(Help(longName: "help", shortName: "h", parsed: { _ in writeHelp() }), at: 0)
         defaultAction = writeHelp
     }
@@ -117,21 +120,27 @@ public class ArgTree: ParserNode {
             helpPrinted()
         }
         // add help as first parse, to play together with the var arg parser
+        Log.debug("creating generated help flag as first parser")
         insert(Help(longName: "help", shortName: "h", parsed: { _ in printHelp() }), at: 0)
         defaultAction = printHelp
     }
 
     @discardableResult
     public func parse(arguments: [String] = CommandLine.arguments) throws -> Int {
         // start parsing from argument 1, since 0 is the name of the script
+        Log.debug("parsing arguments \(arguments) starting from index 1")
         return try parse(arguments: arguments, atIndex: 1, path: []) + 1
 
     }
 
     public func parse(arguments: [String], atIndex i: Int, path: [ParsePathSegment]) throws -> Int {
         if i >= arguments.count {
+            Log.debug("parse index \(i) is out of bounds, number of arguments is \(arguments.count)")
             if let defaultAction = defaultAction {
+                Log.debug("calling default action")
                 defaultAction()
+            } else {
+                Log.debug("no default action set, doing nothing")
             }
             return 0
         }
@@ -144,12 +153,15 @@ internal func parseTree(arguments: [String],
                         atIndex i: Int,
                         path: [ParsePathSegment],
                         childParsers: [Parser]) throws -> Int {
+    Log.debug("parse path is \(path)")
     var i = i
     var totalTokensConsumed = 0
     argumentLoop: while i < arguments.count {
+        Log.debug("next argument to consume is '\(arguments[i])' at index \(i)")
         for parser in childParsers {
             let tokensConsumed = try parser.parse(arguments: arguments, atIndex: i, path: path)
             if tokensConsumed > 0 {
+                Log.debug("child parser \(parser) consumed \(tokensConsumed) arguments")
                 i += tokensConsumed
                 totalTokensConsumed += tokensConsumed
                 continue argumentLoop

Sources/parsers/Command.swift

@@ -60,6 +60,10 @@ open class Command: ValueParser<Bool>, ParserNode {
         }
         return tokensConsumed
     }
+
+    public override var debugDescription: String {
+        return "\(String(describing: Command.self))(\(aliases))"
+    }
 }
 
 /** extension to support collection protocols for parsers */

Sources/parsers/Flag.swift

@@ -1,3 +1,5 @@
+import LoggerAPI
+
 public enum FlagParseError: Error {
     case flagAllowedOnlyOnce(flag: Flag, atIndex: Int)
     case unexpectedFlag(flag: String, atIndex: Int)
@@ -46,6 +48,10 @@ public class Flag: ValueParser<Bool> {
             return true
         }
     }
+
+    public override var debugDescription: String {
+        return "\(String(describing: Flag.self))(\(aliases))"
+    }
 }
 
 /** allows to detect unexpected flags and convert them to errors */
@@ -69,18 +75,26 @@ public class UnexpectedFlagHandler: Parser {
     public func parse(arguments: [String], atIndex i: Int, path: [ParsePathSegment]) throws -> Int {
         let arg = arguments[i]
         if arg == stopToken {
+            Log.debug("stopping parsing on stopToken '\(arg)'")
             return 0
         }
         if let longPrefix = longPrefix {
             if arg.starts(with: longPrefix) {
+                Log.debug("handling unexpected flag '\(arg)' at index \(i)")
                 throw FlagParseError.unexpectedFlag(flag: arg, atIndex: i)
             }
         }
         if let shortPrefix = shortPrefix {
             if arg.starts(with: shortPrefix) {
+                Log.debug("handling unexpected flag '\(arg)' at index \(i)")
                 throw FlagParseError.unexpectedFlag(flag: arg, atIndex: i)
             }
         }
         return 0
     }
+
+    public var debugDescription: String {
+        return "\(String(describing: UnexpectedFlagHandler.self))(\(String(describing: shortPrefix)), " +
+            "\(String(describing: longPrefix)))"
+    }
 }

Sources/parsers/MultiFlag.swift

@@ -1,3 +1,5 @@
+import LoggerAPI
+
 /** parser for mult flags */
 public class MultiFlag: Parser, ParserNode, ParsePathSegment {
 
@@ -21,43 +23,51 @@ public class MultiFlag: Parser, ParserNode, ParsePathSegment {
     public func parse(arguments: [String], atIndex i: Int, path: [ParsePathSegment]) throws -> Int {
         let arg = arguments[i]
         if arg == stopToken {
+            Log.debug("stopping parsing on stopToken '\(arg)'")
             return 0
         }
-        if let j: String.Index = arg.index(of: shortPrefix) {
-            let prefixString = String(shortPrefix)
-            // create full flags
-            let flags: [String] = arg.suffix(from: arg.index(after: j)).map({
-                prefixString + String($0)
-            })
-            // find a valid flag parser for each flag
+        let prefixString = String(shortPrefix)
+        if arg.starts(with: prefixString) {
+            if let j: String.Index = arg.index(of: shortPrefix) {
+                // create full flags
+                let flags: [String] = arg.suffix(from: arg.index(after: j)).map({
+                    prefixString + String($0)
+                })
+                // find a valid flag parser for each flag
 #if swift(>=4.1)
-            let matched: [(parser: Flag, flag: String)] = flags.compactMap({ flag in
-                if let parser = self.parsers
-                    .compactMap({ $0 as? Flag })
-                    .first(where: { parser in parser.aliases.contains(flag) }) {
-                    return (parser: parser, flag: flag)
-                }
-                return nil
-            })
+                let matched: [(parser: Flag, flag: String)] = flags.compactMap({ flag in
+                    if let parser = self.parsers
+                        .compactMap({ $0 as? Flag })
+                        .first(where: { parser in parser.aliases.contains(flag) }) {
+                        return (parser: parser, flag: flag)
+                    }
+                    return nil
+                })
 #else
-            let matched: [(parser: Flag, flag: String)] = flags.flatMap({ flag in
-                if let parser = self.parsers
-                    .flatMap({ $0 as? Flag })
-                    .first(where: { parser in parser.aliases.contains(flag) }) {
-                    return (parser: parser, flag: flag)
-            }
-                return nil
-            })
+                let matched: [(parser: Flag, flag: String)] = flags.flatMap({ flag in
+                    if let parser = self.parsers
+                        .flatMap({ $0 as? Flag })
+                        .first(where: { parser in parser.aliases.contains(flag) }) {
+                        return (parser: parser, flag: flag)
+                    }
+                    return nil
+                })
 #endif
-            // check if all flags are valid flags, do not treat this as multi flag otherwise
-            if matched.count == flags.count {
-                try matched.forEach { parser, flag in
-                    _ = try parser.parse(arguments: arguments[..<i] + [flag], atIndex: i, path: path + [self])
+                // check if all flags are valid flags, do not treat this as multi flag otherwise
+                if matched.count == flags.count {
+                    Log.debug("handling '\(arg)' as multi flag, generated: \(flags)")
+                    try matched.forEach { parser, flag in
+                        _ = try parser.parse(arguments: arguments[..<i] + [flag], atIndex: i, path: path + [self])
+                    }
+                    return 1
+                } else {
+                    Log.debug("'\(arg)' is not a valid multi flag since not all generated flags \(flags) "
+                        + "can be parsed as individual flags")
                 }
-                return 1
             }
         }
         // parse flag normally
+        Log.debug("trying to parse '\(arg)' as normal flag ")
         for parser in parsers {
             let tokensConsumed = try parser.parse(arguments: arguments, atIndex: i, path: path + [self])
             if tokensConsumed > 0 {

Sources/parsers/Option.swift

@@ -1,3 +1,5 @@
+import LoggerAPI
+
 public enum OptionParseError<T>: Error {
     case optionAllowedOnlyOnce(option: OptionParser<T>, atIndex: Int)
     case missingValueForOption(option: OptionParser<T>, atIndex: Int, key: String)
@@ -35,37 +37,41 @@ open class OptionParser<T>: ValueParser<T> {
 
     open override func parse(arguments: [String], atIndex i: Int, path: [ParsePathSegment]) throws -> Int {
         let arg = arguments[i]
-        if stopToken != nil && arg == stopToken {
+        if arg == stopToken {
+            Log.debug("stopping parsing on stopToken '\(arg)'")
             return 0
         }
         for alias in aliases {
             if arg == alias {
-                try checkMultiOption(atIndex: i)
+                try checkMultiOption(arguments: arguments, atIndex: i, path: path)
                 if i + 1 >= arguments.count {
+                    Log.debug("no value for option '\(alias)' could be found for '\(arg)' at index \(i)")
                     throw OptionParseError.missingValueForOption(option: self, atIndex: i, key: arg)
                 }
                 let value = arguments[i + 1]
-                try parseValue(value, atIndex: i + 1, path: path)
+                try parseOption(alias, value: value, atIndex: i + 1, path: path)
                 return 2
             } else if arg.starts(with: alias + "=") {
-                try checkMultiOption(atIndex: i)
+                try checkMultiOption(arguments: arguments, atIndex: i, path: path)
                 let value = arg.suffix(from: arg.index(after: arg.index(of: "=")!))
-                try parseValue(String(value), atIndex: i, path: path)
+                try parseOption(alias, value: String(value), atIndex: i, path: path)
                 return 1
             }
         }
         return 0
     }
 
-    private func checkMultiOption(atIndex i: Int) throws {
+    private func checkMultiOption(arguments: [String], atIndex i: Int, path: [ParsePathSegment]) throws {
         if !multiAllowed && values.count > 0 {
             // if the option has been parsed once, it is not allowed a second time, if not explicitly allowed
             // by multiAllowed
+            Log.debug("not allowed to pass option '\(aliases)' multiple times at index \(i)")
             throw OptionParseError.optionAllowedOnlyOnce(option: self, atIndex: i)
         }
     }
 
-    private func parseValue(_ value: String, atIndex i: Int, path: [ParsePathSegment]) throws {
+    private func parseOption(_ option: String, value: String, atIndex i: Int, path: [ParsePathSegment]) throws {
+        Log.debug("parsing option '\(option)' at index \(i), value is '\(value)'")
         if let converter = valueConverter {
             let value = try converter(value, i)
             self.values.append(value)
@@ -75,6 +81,10 @@ open class OptionParser<T>: ValueParser<T> {
         }
 
     }
+
+    public override var debugDescription: String {
+        return "\(String(describing: OptionParser.self))(\(aliases))"
+    }
 }
 
 public class Option: OptionParser<String> {
@@ -98,6 +108,10 @@ public class Option: OptionParser<String> {
             return value
         }
     }
+
+    public override var debugDescription: String {
+        return "\(String(describing: Option.self))(\(aliases))"
+    }
 }
 
 public class IntOption: OptionParser<Int> {
@@ -121,9 +135,14 @@ public class IntOption: OptionParser<Int> {
             if let value = Int(value) {
                 return value
             }
+            Log.debug("value '\(value)' cannot be converted to Int option")
             throw OptionParseError.valueNotIntConvertible(option: self, atIndex: i, value: value)
         }
     }
+
+    public override var debugDescription: String {
+        return "\(String(describing: IntOption.self))(\(aliases))"
+    }
 }
 
 public class DoubleOption: OptionParser<Double> {
@@ -147,9 +166,13 @@ public class DoubleOption: OptionParser<Double> {
             if let value = Double(value) {
                 return value
             }
+            Log.debug("value '\(value)' cannot be converted to Double option")
             throw OptionParseError.valueNotDoubleConvertible(option: self, atIndex: i, value: value)
         }
     }
+    public override var debugDescription: String {
+        return "\(String(describing: DoubleOption.self))(\(aliases))"
+    }
 }
 
 /** allows to detect unexpected flags and convert them to errors */
@@ -173,18 +196,25 @@ public class UnexpectedOptionHandler: Parser {
     public func parse(arguments: [String], atIndex i: Int, path: [ParsePathSegment]) throws -> Int {
         let arg = arguments[i]
         if arg == stopToken {
+            Log.debug("stopping parsing on stopToken '\(arg)'")
             return 0
         }
         if let longPrefix = longPrefix {
             if arg.starts(with: longPrefix) {
+                Log.debug("handling unexpected option '\(arg)' at index \(i)")
                 throw OptionParseError<Void>.unexpectedOption(option: arg, atIndex: i)
             }
         }
         if let shortPrefix = shortPrefix {
             if arg.starts(with: shortPrefix) {
+                Log.debug("handling unexpected option '\(arg)' at index \(i)")
                 throw OptionParseError<Void>.unexpectedOption(option: arg, atIndex: i)
             }
         }
         return 0
     }
+
+    public var debugDescription: String {
+        return "\(String(describing: UnexpectedOptionHandler.self))"
+    }
 }