From 97e4caf57f4fce01ced0f08f2b8e3f89ed76ff96 Mon Sep 17 00:00:00 2001 From: tanner0101 Date: Fri, 26 Jun 2020 12:02:30 -0400 Subject: [PATCH 1/3] logging improvements --- .../Authentication/AuthenticationCache.swift | 1 - .../Vapor/Authentication/Authenticator.swift | 1 - Sources/Vapor/Error/AbortError.swift | 5 +++ Sources/Vapor/Error/DebuggableError.swift | 36 ++++++------------- Sources/Vapor/HTTP/Server/HTTPServer.swift | 2 +- Sources/Vapor/Logging/Logger+Report.swift | 14 +++++--- Sources/Vapor/Request/Request.swift | 4 +-- .../Vapor/Responder/DefaultResponder.swift | 20 ++++++++++- 8 files changed, 47 insertions(+), 36 deletions(-) diff --git a/Sources/Vapor/Authentication/AuthenticationCache.swift b/Sources/Vapor/Authentication/AuthenticationCache.swift index ea7631f49d..59c34035fc 100755 --- a/Sources/Vapor/Authentication/AuthenticationCache.swift +++ b/Sources/Vapor/Authentication/AuthenticationCache.swift @@ -36,7 +36,6 @@ extension Request.Authentication { where A: Authenticatable { guard let a = self.get(A.self) else { - self.request.logger.error("\(A.self) has not been authorized") throw Abort(.unauthorized) } return a diff --git a/Sources/Vapor/Authentication/Authenticator.swift b/Sources/Vapor/Authentication/Authenticator.swift index 34298fdb39..5aba4666dd 100755 --- a/Sources/Vapor/Authentication/Authenticator.swift +++ b/Sources/Vapor/Authentication/Authenticator.swift @@ -68,7 +68,6 @@ extension CredentialsAuthenticator { do { credentials = try request.content.decode(Credentials.self) } catch { - request.logger.error("Could not decode credentials: \(error)") return request.eventLoop.makeSucceededFuture(()) } return self.authenticate(credentials: credentials, for: request) diff --git a/Sources/Vapor/Error/AbortError.swift b/Sources/Vapor/Error/AbortError.swift index a0acad97b6..59bc311b93 100644 --- a/Sources/Vapor/Error/AbortError.swift +++ b/Sources/Vapor/Error/AbortError.swift @@ -24,6 +24,11 @@ extension AbortError { public var headers: HTTPHeaders { [:] } + + /// See `AbortError`. + public var reason: String { + self.status.reasonPhrase + } } extension AbortError where Self: DebuggableError { diff --git a/Sources/Vapor/Error/DebuggableError.swift b/Sources/Vapor/Error/DebuggableError.swift index 501582981e..c998f3510f 100644 --- a/Sources/Vapor/Error/DebuggableError.swift +++ b/Sources/Vapor/Error/DebuggableError.swift @@ -54,6 +54,10 @@ public protocol DebuggableError: LocalizedError, CustomDebugStringConvertible, C /// - note: Defaults to an empty array. /// Provide a custom implementation to a list of pertinent issues. var gitHubIssues: [String] { get } + + /// Which log level this error should report as. + /// Defaults to `.error`. + var logLevel: Logger.Level { get } } extension DebuggableError { @@ -100,6 +104,10 @@ extension DebuggableError { public var stackTrace: StackTrace? { nil } + + public var logLevel: Logger.Level { + .error + } } /// MARK: Custom...StringConvertible @@ -154,34 +162,10 @@ extension DebuggableError { var print: [String] = [] switch format { - case .long: - print.append("\(Self.readableName): \(self.reason)\n- id: \(self.fullIdentifier)") - case .short: + case .long, .short: print.append("\(self.fullIdentifier): \(self.reason)") } - if let source = self.source { - switch format { - case .long: - var help: [String] = [] - help.append("File: \(source.file)") - help.append("- func: \(source.function)") - help.append("- line: \(source.line)") - help.append("- column: \(source.column)") - if let range = source.range { - help.append("- range: \(range)") - } - print.append(help.joined(separator: "\n")) - case .short: - var string = "[\(source.file):\(source.line):\(source.column)" - if let range = source.range { - string += " (\(range))" - } - string += "]" - print.append(string) - } - } - switch format { case .long: if !self.possibleCauses.isEmpty { @@ -217,7 +201,7 @@ extension DebuggableError { switch format { case .long: - return print.joined(separator: "\n\n") + return print.joined(separator: "\n") + "\n" case .short: return print.joined(separator: " ") } diff --git a/Sources/Vapor/HTTP/Server/HTTPServer.swift b/Sources/Vapor/HTTP/Server/HTTPServer.swift index aec5bfac79..034fee2104 100644 --- a/Sources/Vapor/HTTP/Server/HTTPServer.swift +++ b/Sources/Vapor/HTTP/Server/HTTPServer.swift @@ -331,7 +331,7 @@ final class HTTPServerErrorHandler: ChannelInboundHandler { } func errorCaught(context: ChannelHandlerContext, error: Error) { - self.logger.error("Unhandled HTTP server error: \(error)") + self.logger.debug("Unhandled HTTP server error: \(error)") context.close(mode: .output, promise: nil) } } diff --git a/Sources/Vapor/Logging/Logger+Report.swift b/Sources/Vapor/Logging/Logger+Report.swift index c568840bab..efe403d590 100644 --- a/Sources/Vapor/Logging/Logger+Report.swift +++ b/Sources/Vapor/Logging/Logger+Report.swift @@ -11,29 +11,35 @@ extension Logger { ) { let source: ErrorSource? let reason: String + let level: Logger.Level switch error { case let debuggable as DebuggableError: - if self.logLevel <= .debug { - reason = debuggable.debuggableHelp(format: .short) - } else { + if self.logLevel <= .trace { reason = debuggable.debuggableHelp(format: .long) + } else { + reason = debuggable.debuggableHelp(format: .short) } source = debuggable.source + level = debuggable.logLevel case let abort as AbortError: reason = abort.reason source = nil + level = .error case let localized as LocalizedError: reason = localized.localizedDescription source = nil + level = .error case let convertible as CustomStringConvertible: reason = convertible.description source = nil + level = .error default: reason = "\(error)" source = nil + level = .error } self.log( - level: .error, + level: level, .init(stringLiteral: reason), file: source?.file ?? file, function: source?.function ?? function, diff --git a/Sources/Vapor/Request/Request.swift b/Sources/Vapor/Request/Request.swift index d190473d42..48fc59ffbc 100644 --- a/Sources/Vapor/Request/Request.swift +++ b/Sources/Vapor/Request/Request.swift @@ -73,7 +73,7 @@ public final class Request: CustomStringConvertible { func decode(_ decodable: D.Type, using decoder: ContentDecoder) throws -> D where D : Decodable { guard let body = self.request.body.data else { - self.request.logger.error("Decoding streaming bodies not supported") + self.request.logger.debug("Decoding streaming bodies not supported") throw Abort(.unprocessableEntity) } return try decoder.decode(D.self, from: body, headers: self.request.headers) @@ -89,7 +89,7 @@ public final class Request: CustomStringConvertible { func decode(_ content: C.Type, using decoder: ContentDecoder) throws -> C where C : Content { guard let body = self.request.body.data else { - self.request.logger.error("Decoding streaming bodies not supported") + self.request.logger.debug("Decoding streaming bodies not supported") throw Abort(.unprocessableEntity) } var decoded = try decoder.decode(C.self, from: body, headers: self.request.headers) diff --git a/Sources/Vapor/Responder/DefaultResponder.swift b/Sources/Vapor/Responder/DefaultResponder.swift index d16aaaac90..a424903cf0 100644 --- a/Sources/Vapor/Responder/DefaultResponder.swift +++ b/Sources/Vapor/Responder/DefaultResponder.swift @@ -111,6 +111,24 @@ internal struct DefaultResponder: Responder { private struct NotFoundResponder: Responder { func respond(to request: Request) -> EventLoopFuture { - request.eventLoop.makeFailedFuture(Abort(.notFound)) + request.eventLoop.makeFailedFuture(RouteNotFound()) } } + +struct RouteNotFound: Error { } + +extension RouteNotFound: AbortError { + static var typeIdentifier: String { + "Abort" + } + + var status: HTTPResponseStatus { + .notFound + } +} + +extension RouteNotFound: DebuggableError { + var logLevel: Logger.Level { + .debug + } +} \ No newline at end of file From 221e5326ff25b316cd17ef31cc09b938cd45f5a2 Mon Sep 17 00:00:00 2001 From: tanner0101 Date: Fri, 26 Jun 2020 12:14:42 -0400 Subject: [PATCH 2/3] fix error test expectations --- Tests/VaporTests/ErrorTests.swift | 12 ++++-------- 1 file changed, 4 insertions(+), 8 deletions(-) diff --git a/Tests/VaporTests/ErrorTests.swift b/Tests/VaporTests/ErrorTests.swift index 51ec117990..22c6f0682b 100644 --- a/Tests/VaporTests/ErrorTests.swift +++ b/Tests/VaporTests/ErrorTests.swift @@ -4,24 +4,20 @@ import Vapor final class ErrorTests: XCTestCase { func testPrintable() throws { print(FooError.noFoo.debugDescription) - let expectedPrintable = """ - Foo Error: You do not have a `foo`. - - id: FooError.noFoo - + FooError.noFoo: You do not have a `foo`. Here are some possible causes: - You did not set the flongwaffle. - The session ended before a `Foo` could be made. - The universe conspires against us all. - Computers are hard. - These suggestions could address the issue: - You really want to use a `Bar` here. - Take up the guitar and move to the beach. - Vapor's documentation talks about this: - http://documentation.com/Foo - http://documentation.com/foo/noFoo + """ XCTAssertEqual(FooError.noFoo.debugDescription, expectedPrintable) } @@ -64,8 +60,8 @@ final class ErrorTests: XCTestCase { let minimum = MinimumError.alpha let description = minimum.debugDescription let expectation = """ - MinimumError: Not enabled - - id: MinimumError.alpha + MinimumError.alpha: Not enabled + """ XCTAssertEqual(description, expectation) } From 7106da3651e654d0bc46440e146a2cc4e0b1668f Mon Sep 17 00:00:00 2001 From: tanner0101 Date: Fri, 26 Jun 2020 12:24:44 -0400 Subject: [PATCH 3/3] stacktrace capture --- Sources/Development/routes.swift | 4 ++-- Sources/Vapor/Logging/LoggingSystem+Environment.swift | 4 ++-- 2 files changed, 4 insertions(+), 4 deletions(-) diff --git a/Sources/Development/routes.swift b/Sources/Development/routes.swift index 24a1ca2d6e..e28a0d4a05 100644 --- a/Sources/Development/routes.swift +++ b/Sources/Development/routes.swift @@ -208,7 +208,7 @@ public func routes(_ app: Application) throws { } } -struct TestError: AbortError { +struct TestError: AbortError, DebuggableError { var status: HTTPResponseStatus { .internalServerError } @@ -226,7 +226,7 @@ struct TestError: AbortError { line: UInt = #line, column: UInt = #column, range: Range? = nil, - stackTrace: StackTrace? = .capture() + stackTrace: StackTrace? = .capture(skip: 1) ) { self.source = .init( file: file, diff --git a/Sources/Vapor/Logging/LoggingSystem+Environment.swift b/Sources/Vapor/Logging/LoggingSystem+Environment.swift index 51e0ef6c30..2dece93f06 100644 --- a/Sources/Vapor/Logging/LoggingSystem+Environment.swift +++ b/Sources/Vapor/Logging/LoggingSystem+Environment.swift @@ -11,8 +11,8 @@ extension LoggingSystem { ?? Environment.process.LOG_LEVEL ?? (environment == .production ? .notice: .info) - // Disable stack traces if log level > debug. - if level > .debug { + // Disable stack traces if log level > trace. + if level > .trace { StackTrace.isCaptureEnabled = false }