Skip to content

Commit b286e64

Browse files
adam-fowleradam-fowler
authored
Metrics and Logging name changes (#541)
1 parent b482bb7 commit b286e64

File tree

9 files changed

+74
-56
lines changed

9 files changed

+74
-56
lines changed

‎Sources/Hummingbird/Application.swift

+2-2
Original file line numberDiff line numberDiff line change
@@ -102,7 +102,7 @@ extension ApplicationProtocol {
102102
eventLoopGroup: self.eventLoopGroup,
103103
logger: self.logger
104104
) { (request, responseWriter: consuming ResponseWriter, channel) in
105-
let logger = self.logger.with(metadataKey: "hb_id", value: .stringConvertible(RequestID()))
105+
let logger = self.logger.with(metadataKey: "hb.request.id", value: .stringConvertible(RequestID()))
106106
let context = Self.Responder.Context(
107107
source: .init(
108108
channel: channel,
@@ -114,7 +114,7 @@ extension ApplicationProtocol {
114114
do {
115115
response = try await responder.respond(to: request, context: context)
116116
} catch {
117-
logger.debug("Unrecognised Error", metadata: ["error": "\(error)"])
117+
logger.debug("Unrecognised Error", metadata: ["error.type": "\(error)"])
118118
response = Response(
119119
status: .internalServerError,
120120
body: .init()

‎Sources/Hummingbird/Files/FileIO.swift

+2-2
Original file line numberDiff line numberDiff line change
@@ -79,7 +79,7 @@ public struct FileIO: Sendable {
7979
path: String,
8080
context: some RequestContext
8181
) async throws where AS.Element == ByteBuffer {
82-
context.logger.debug("[FileIO] PUT", metadata: ["file": .string(path)])
82+
context.logger.debug("[FileIO] PUT", metadata: ["hb.file.path": .string(path)])
8383
try await self.fileIO.withFileHandle(path: path, mode: .write, flags: .allowFileCreation()) { handle in
8484
for try await buffer in contents {
8585
try await self.fileIO.write(fileHandle: handle, buffer: buffer)
@@ -98,7 +98,7 @@ public struct FileIO: Sendable {
9898
path: String,
9999
context: some RequestContext
100100
) async throws {
101-
context.logger.debug("[FileIO] PUT", metadata: ["file": .string(path)])
101+
context.logger.debug("[FileIO] PUT", metadata: ["hb.file.path": .string(path)])
102102
try await self.fileIO.withFileHandle(path: path, mode: .write, flags: .allowFileCreation()) { handle in
103103
try await self.fileIO.write(fileHandle: handle, buffer: buffer)
104104
}

‎Sources/Hummingbird/Middleware/LogRequestMiddleware.swift

+8-8
Original file line numberDiff line numberDiff line change
@@ -72,28 +72,28 @@ public struct LogRequestsMiddleware<Context: RequestContext>: RouterMiddleware {
7272
level: self.logLevel,
7373
"Request",
7474
metadata: [
75-
"hb_uri": .stringConvertible(request.uri),
76-
"hb_method": .string(request.method.rawValue),
75+
"hb.request.path": .stringConvertible(request.uri),
76+
"hb.request.method": .string(request.method.rawValue),
7777
]
7878
)
7979
case .all(let except):
8080
context.logger.log(
8181
level: self.logLevel,
8282
"Request",
8383
metadata: [
84-
"hb_uri": .stringConvertible(request.uri),
85-
"hb_method": .string(request.method.rawValue),
86-
"hb_headers": .stringConvertible(self.allHeaders(headers: request.headers, except: except)),
84+
"hb.request.path": .stringConvertible(request.uri),
85+
"hb.request.method": .string(request.method.rawValue),
86+
"hb.request.headers": .stringConvertible(self.allHeaders(headers: request.headers, except: except)),
8787
]
8888
)
8989
case .some(let filter):
9090
context.logger.log(
9191
level: self.logLevel,
9292
"Request",
9393
metadata: [
94-
"hb_uri": .stringConvertible(request.uri),
95-
"hb_method": .string(request.method.rawValue),
96-
"hb_headers": .stringConvertible(self.filterHeaders(headers: request.headers, filter: filter)),
94+
"hb.request.path": .stringConvertible(request.uri),
95+
"hb.request.method": .string(request.method.rawValue),
96+
"hb.request.headers": .stringConvertible(self.filterHeaders(headers: request.headers, filter: filter)),
9797
]
9898
)
9999
}

‎Sources/Hummingbird/Middleware/MetricsMiddleware.swift

+23-11
Original file line numberDiff line numberDiff line change
@@ -24,42 +24,54 @@ public struct MetricsMiddleware<Context: RequestContext>: RouterMiddleware {
2424

2525
public func handle(_ request: Request, context: Context, next: (Request, Context) async throws -> Response) async throws -> Response {
2626
let startTime = DispatchTime.now().uptimeNanoseconds
27-
27+
let activeRequestMeter = Meter(label: "cod", dimensions: [("http.request.method", request.method.description)])
28+
activeRequestMeter.increment()
2829
do {
2930
var response = try await next(request, context)
31+
let responseStatus = response.status
3032
response.body = response.body.withPostWriteClosure {
3133
// need to create dimensions once request has been responded to ensure
3234
// we have the correct endpoint path
3335
let dimensions: [(String, String)] = [
34-
("hb_uri", context.endpointPath ?? request.uri.path),
35-
("hb_method", request.method.rawValue),
36+
("http.route", context.endpointPath ?? request.uri.path),
37+
("http.request.method", request.method.rawValue),
38+
("http.response.status_code", responseStatus.code.description),
3639
]
37-
Counter(label: "hb_requests", dimensions: dimensions).increment()
40+
Counter(label: "hb.requests", dimensions: dimensions).increment()
3841
Metrics.Timer(
39-
label: "hb_request_duration",
42+
label: "http.server.request.duration",
4043
dimensions: dimensions,
4144
preferredDisplayUnit: .seconds
4245
).recordNanoseconds(DispatchTime.now().uptimeNanoseconds - startTime)
46+
activeRequestMeter.decrement()
4347
}
4448
return response
4549
} catch {
50+
let errorType: String
51+
if let httpError = error as? HTTPResponseError {
52+
errorType = httpError.status.code.description
53+
} else {
54+
errorType = "500"
55+
}
4656
// need to create dimensions once request has been responded to ensure
4757
// we have the correct endpoint path
4858
let dimensions: [(String, String)]
4959
// Don't record uri in 404 errors, to avoid spamming of metrics
5060
if let endpointPath = context.endpointPath {
5161
dimensions = [
52-
("hb_uri", endpointPath),
53-
("hb_method", request.method.rawValue),
62+
("http.route", endpointPath),
63+
("http.request.method", request.method.rawValue),
64+
("error.type", errorType),
5465
]
55-
Counter(label: "hb_requests", dimensions: dimensions).increment()
66+
Counter(label: "hb.requests", dimensions: dimensions).increment()
5667
} else {
5768
dimensions = [
58-
("hb_uri", "NotFound"),
59-
("hb_method", request.method.rawValue),
69+
("http.request.method", request.method.rawValue),
70+
("error.type", errorType),
6071
]
6172
}
62-
Counter(label: "hb_errors", dimensions: dimensions).increment()
73+
Counter(label: "hb.request.errors", dimensions: dimensions).increment()
74+
activeRequestMeter.decrement()
6375
throw error
6476
}
6577
}

‎Sources/Hummingbird/Server/RequestContext.swift

+1-1
Original file line numberDiff line numberDiff line change
@@ -92,7 +92,7 @@ extension RequestContext {
9292
public var parameters: Parameters { coreContext.parameters }
9393
/// Request ID, extracted from Logger
9494
@inlinable
95-
public var id: String { self.logger[metadataKey: "hb_id"]!.description }
95+
public var id: String { self.logger[metadataKey: "hb.request.id"]!.description }
9696
}
9797

9898
extension RequestContext where Decoder == JSONDecoder {

‎Sources/HummingbirdTesting/RouterTestFramework.swift

+1-1
Original file line numberDiff line numberDiff line change
@@ -108,7 +108,7 @@ struct RouterTestFramework<Responder: HTTPResponder>: ApplicationTestFramework w
108108
head: .init(method: method, scheme: "http", authority: "localhost", path: uri, headerFields: headers),
109109
body: stream
110110
)
111-
let logger = self.logger.with(metadataKey: "hb_id", value: .stringConvertible(RequestID()))
111+
let logger = self.logger.with(metadataKey: "hb.request.id", value: .stringConvertible(RequestID()))
112112
let context = self.makeContext(logger)
113113

114114
group.addTask {

‎Sources/PerformanceTest/main.swift

+4
Original file line numberDiff line numberDiff line change
@@ -25,6 +25,10 @@ let port = env.get("SERVER_PORT", as: Int.self) ?? 8080
2525
// create app
2626
let elg = MultiThreadedEventLoopGroup(numberOfThreads: 4)
2727
var router = Router()
28+
router.addMiddleware {
29+
LogRequestsMiddleware(.info)
30+
}
31+
2832
// number of raw requests
2933
// ./wrk -c 128 -d 15s -t 8 http://localhost:8080
3034
router.get { _, _ in

‎Tests/HummingbirdTests/MetricsTests.swift

+18-16
Original file line numberDiff line numberDiff line change
@@ -200,11 +200,11 @@ final class MetricsTests: XCTestCase {
200200
try await client.execute(uri: "/hello", method: .get) { _ in }
201201
}
202202

203-
let counter = try XCTUnwrap(Self.testMetrics.counters.withLockedValue { $0 }["hb_requests"] as? TestCounter)
203+
let counter = try XCTUnwrap(Self.testMetrics.counters.withLockedValue { $0 }["hb.requests"] as? TestCounter)
204204
XCTAssertEqual(counter.values.withLockedValue { $0 }[0].1, 1)
205-
XCTAssertEqual(counter.dimensions[0].0, "hb_uri")
205+
XCTAssertEqual(counter.dimensions[0].0, "http.route")
206206
XCTAssertEqual(counter.dimensions[0].1, "/hello")
207-
XCTAssertEqual(counter.dimensions[1].0, "hb_method")
207+
XCTAssertEqual(counter.dimensions[1].0, "http.request.method")
208208
XCTAssertEqual(counter.dimensions[1].1, "GET")
209209
}
210210

@@ -219,12 +219,12 @@ final class MetricsTests: XCTestCase {
219219
try await client.execute(uri: "/hello", method: .get) { _ in }
220220
}
221221

222-
let counter = try XCTUnwrap(Self.testMetrics.counters.withLockedValue { $0 }["hb_errors"] as? TestCounter)
222+
let counter = try XCTUnwrap(Self.testMetrics.counters.withLockedValue { $0 }["hb.request.errors"] as? TestCounter)
223223
XCTAssertEqual(counter.values.withLockedValue { $0 }.count, 1)
224224
XCTAssertEqual(counter.values.withLockedValue { $0 }[0].1, 1)
225-
XCTAssertEqual(counter.dimensions[0].0, "hb_uri")
225+
XCTAssertEqual(counter.dimensions[0].0, "http.route")
226226
XCTAssertEqual(counter.dimensions[0].1, "/hello")
227-
XCTAssertEqual(counter.dimensions[1].0, "hb_method")
227+
XCTAssertEqual(counter.dimensions[1].0, "http.request.method")
228228
XCTAssertEqual(counter.dimensions[1].1, "GET")
229229
}
230230

@@ -239,14 +239,14 @@ final class MetricsTests: XCTestCase {
239239
try await client.execute(uri: "/hello2", method: .get) { _ in }
240240
}
241241

242-
let counter = try XCTUnwrap(Self.testMetrics.counters.withLockedValue { $0 }["hb_errors"] as? TestCounter)
242+
let counter = try XCTUnwrap(Self.testMetrics.counters.withLockedValue { $0 }["hb.request.errors"] as? TestCounter)
243243
XCTAssertEqual(counter.values.withLockedValue { $0 }.count, 1)
244244
XCTAssertEqual(counter.values.withLockedValue { $0 }[0].1, 1)
245245
XCTAssertEqual(counter.dimensions.count, 2)
246-
XCTAssertEqual(counter.dimensions[0].0, "hb_uri")
247-
XCTAssertEqual(counter.dimensions[0].1, "NotFound")
248-
XCTAssertEqual(counter.dimensions[1].0, "hb_method")
249-
XCTAssertEqual(counter.dimensions[1].1, "GET")
246+
XCTAssertEqual(counter.dimensions[0].0, "http.request.method")
247+
XCTAssertEqual(counter.dimensions[0].1, "GET")
248+
XCTAssertEqual(counter.dimensions[1].0, "error.type")
249+
XCTAssertEqual(counter.dimensions[1].1, "404")
250250
}
251251

252252
func testParameterEndpoint() async throws {
@@ -260,14 +260,16 @@ final class MetricsTests: XCTestCase {
260260
try await client.execute(uri: "/user/765", method: .get) { _ in }
261261
}
262262

263-
let counter = try XCTUnwrap(Self.testMetrics.counters.withLockedValue { $0 }["hb_errors"] as? TestCounter)
263+
let counter = try XCTUnwrap(Self.testMetrics.counters.withLockedValue { $0 }["hb.request.errors"] as? TestCounter)
264264
XCTAssertEqual(counter.values.withLockedValue { $0 }.count, 1)
265265
XCTAssertEqual(counter.values.withLockedValue { $0 }[0].1, 1)
266-
XCTAssertEqual(counter.dimensions.count, 2)
267-
XCTAssertEqual(counter.dimensions[0].0, "hb_uri")
266+
XCTAssertEqual(counter.dimensions.count, 3)
267+
XCTAssertEqual(counter.dimensions[0].0, "http.route")
268268
XCTAssertEqual(counter.dimensions[0].1, "/user/{id}")
269-
XCTAssertEqual(counter.dimensions[1].0, "hb_method")
269+
XCTAssertEqual(counter.dimensions[1].0, "http.request.method")
270270
XCTAssertEqual(counter.dimensions[1].1, "GET")
271+
XCTAssertEqual(counter.dimensions[2].0, "error.type")
272+
XCTAssertEqual(counter.dimensions[2].1, "400")
271273
}
272274

273275
func testRecordingBodyWriteTime() async throws {
@@ -283,7 +285,7 @@ final class MetricsTests: XCTestCase {
283285
try await client.execute(uri: "/hello", method: .get) { _ in }
284286
}
285287

286-
let timer = try XCTUnwrap(Self.testMetrics.timers.withLockedValue { $0 }["hb_request_duration"] as? TestTimer)
288+
let timer = try XCTUnwrap(Self.testMetrics.timers.withLockedValue { $0 }["http.server.request.duration"] as? TestTimer)
287289
XCTAssertGreaterThan(timer.values.withLockedValue { $0 }[0].1, 5_000_000)
288290
}
289291
}

‎Tests/HummingbirdTests/MiddlewareTests.swift

+15-15
Original file line numberDiff line numberDiff line change
@@ -316,10 +316,10 @@ final class MiddlewareTests: XCTestCase {
316316
headers: [.contentType: "application/json"],
317317
body: .init(string: "{}")
318318
) { _ in
319-
let logs = logAccumalator.filter { $0.metadata?["hb_uri"]?.description == "/test" }
319+
let logs = logAccumalator.filter { $0.metadata?["hb.request.path"]?.description == "/test" }
320320
let firstLog = try XCTUnwrap(logs.first)
321-
XCTAssertEqual(firstLog.metadata?["hb_method"]?.description, "GET")
322-
XCTAssertNotNil(firstLog.metadata?["hb_id"])
321+
XCTAssertEqual(firstLog.metadata?["hb.request.method"]?.description, "GET")
322+
XCTAssertNotNil(firstLog.metadata?["hb.request.id"])
323323
}
324324
}
325325
}
@@ -349,26 +349,26 @@ final class MiddlewareTests: XCTestCase {
349349
headers: [.contentType: "application/json"],
350350
body: .init(string: "{}")
351351
) { _ in
352-
let logEntries = logAccumalator.filter { $0.metadata?["hb_uri"]?.description == "/some" }
353-
XCTAssertEqual(logEntries.first?.metadata?["hb_headers"], .stringConvertible(["content-type": "application/json"]))
352+
let logEntries = logAccumalator.filter { $0.metadata?["hb.request.path"]?.description == "/some" }
353+
XCTAssertEqual(logEntries.first?.metadata?["hb.request.headers"], .stringConvertible(["content-type": "application/json"]))
354354
}
355355
try await client.execute(
356356
uri: "/none",
357357
method: .get,
358358
headers: [.contentType: "application/json"],
359359
body: .init(string: "{}")
360360
) { _ in
361-
let logEntries = logAccumalator.filter { $0.metadata?["hb_uri"]?.description == "/none" }
362-
XCTAssertNil(logEntries.first?.metadata?["hb_headers"])
361+
let logEntries = logAccumalator.filter { $0.metadata?["hb.request.path"]?.description == "/none" }
362+
XCTAssertNil(logEntries.first?.metadata?["hb.request.headers"])
363363
}
364364
try await client.execute(
365365
uri: "/all",
366366
method: .get,
367367
headers: [.contentType: "application/json"],
368368
body: .init(string: "{}")
369369
) { _ in
370-
let logEntries = logAccumalator.filter { $0.metadata?["hb_uri"]?.description == "/all" }
371-
guard case .stringConvertible(let headers) = logEntries.first?.metadata?["hb_headers"] else {
370+
let logEntries = logAccumalator.filter { $0.metadata?["hb.request.path"]?.description == "/all" }
371+
guard case .stringConvertible(let headers) = logEntries.first?.metadata?["hb.request.headers"] else {
372372
fatalError("Should never get here")
373373
}
374374
let reportedHeaders = try XCTUnwrap(headers as? [String: String])
@@ -401,17 +401,17 @@ final class MiddlewareTests: XCTestCase {
401401
headers: [.authorization: "basic okhasdf87654"],
402402
body: .init(string: "{}")
403403
) { _ in
404-
let logEntries = logAccumalator.filter { $0.metadata?["hb_uri"]?.description == "/some" }
405-
XCTAssertEqual(logEntries.first?.metadata?["hb_headers"], .stringConvertible(["authorization": "***"]))
404+
let logEntries = logAccumalator.filter { $0.metadata?["hb.request.path"]?.description == "/some" }
405+
XCTAssertEqual(logEntries.first?.metadata?["hb.request.headers"], .stringConvertible(["authorization": "***"]))
406406
}
407407
try await client.execute(
408408
uri: "/all",
409409
method: .get,
410410
headers: [.authorization: "basic kjhdfi7udsfkhj"],
411411
body: .init(string: "{}")
412412
) { _ in
413-
let logEntries = logAccumalator.filter { $0.metadata?["hb_uri"]?.description == "/all" }
414-
guard case .stringConvertible(let headers) = logEntries.first?.metadata?["hb_headers"] else {
413+
let logEntries = logAccumalator.filter { $0.metadata?["hb.request.path"]?.description == "/all" }
414+
guard case .stringConvertible(let headers) = logEntries.first?.metadata?["hb.request.headers"] else {
415415
fatalError("Should never get here")
416416
}
417417
let reportedHeaders = try XCTUnwrap(headers as? [String: String])
@@ -444,9 +444,9 @@ final class MiddlewareTests: XCTestCase {
444444
headers: headers,
445445
body: .init(string: "{}")
446446
) { _ in
447-
let logs = logAccumalator.filter { $0.metadata?["hb_uri"]?.description == "/test" }
447+
let logs = logAccumalator.filter { $0.metadata?["hb.request.path"]?.description == "/test" }
448448
let firstLog = try XCTUnwrap(logs.first)
449-
XCTAssertEqual(firstLog.metadata?["hb_headers"], .stringConvertible(["hbtest": "One, Two"]))
449+
XCTAssertEqual(firstLog.metadata?["hb.request.headers"], .stringConvertible(["hbtest": "One, Two"]))
450450
}
451451
}
452452
}

0 commit comments

Comments
 (0)