Report relay errors to an operator-run GlitchTip, off unless FN_SENTRY_DSN is set
A minimal Sentry envelope sender over Vapor's client, no new dependency. Errors, criticals and 5xx responses each become one event; warnings stay on stdout; info and debug are never sent. An event is an allowlist: level, scrubbed message, error type, route template, method, status, fingerprint and the log call's source line. No headers, bodies, query strings, addresses, user block or logger metadata (Vapor's ErrorMiddleware attaches the full URL and User-Agent there; it is dropped unread). Scrubbing removes route parameter and query values by value first, so a username is caught whatever its shape, then UUIDs, fnids, JWTs, bearer and key=value secrets, SQL key details, emails, IPv4/IPv6, phone numbers, hex and token-shaped runs, long numbers and identifiers after words like device, account, attachment and report. 30 events a minute, one per fingerprint per 60 seconds, 2 second timeout, fire and forget, no retries. A request's errors are collected on its logger and sent once with its route and status. WireErrorMiddleware's path masking moves to PathMask, output unchanged. FN_SENTRY_DSN is documented in docs/CONFIGURATION.md and the generated configuration page. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
This commit is contained in:
Paul Hitt
co-authored by
Claude Opus 5.5
Claude Opus 5.5
parent
f11e32d0a9
commit
98dcc210ad
@@ -3,7 +3,7 @@
|
||||
<!-- GENERATED by Scripts/build-doc-pages.sh from docs/CONFIGURATION.md.
|
||||
Edits made HERE are deleted the next time that script runs.
|
||||
Change the markdown source and re-run it.
|
||||
source-sha256: 272724e75c56bd0b -->
|
||||
source-sha256: 9d20067215874430 -->
|
||||
<article class="band doc doc-generated">
|
||||
<div class="wrap wrap-narrow">
|
||||
<h1 id="configuring-a-relay">Configuring a relay</h1>
|
||||
@@ -258,6 +258,24 @@ front of it.</td>
|
||||
<td>Never raise to <code>debug</code> on a machine with real accounts:
|
||||
it logs request URLs, and a protocol URL contains a device id.</td>
|
||||
</tr>
|
||||
<tr>
|
||||
<td><code>FN_SENTRY_DSN</code></td>
|
||||
<td>unset</td>
|
||||
<td>Error reporting to a Sentry-protocol collector you run (GlitchTip),
|
||||
as
|
||||
<code>http://<key>@<host>:<port>/<project></code>.
|
||||
Unset sends nothing. Set, errors, criticals and 5xx responses each
|
||||
become one event: the message with account ids, device ids, addresses,
|
||||
tokens, emails and phone numbers removed, the error type, the route
|
||||
template (<code>/e2e/devices/:deviceID</code>, never the path asked
|
||||
for), method, status and the source line. No headers, bodies, query
|
||||
strings, addresses or logger metadata. Warnings stay on stdout; info and
|
||||
debug are never sent. At most 30 events a minute, one per fault per 60
|
||||
seconds, 2 second timeout, no retries. The collector keeps what it
|
||||
receives for as long as it is configured to, so point it at one whose
|
||||
retention you have chosen. A value that is not a DSN stops the relay at
|
||||
start-up.</td>
|
||||
</tr>
|
||||
</tbody>
|
||||
</table>
|
||||
<p><strong>HTTPS is not optional in practice.</strong> Clients hold key
|
||||
|
||||
@@ -17,7 +17,17 @@ enum Entrypoint {
|
||||
exit(await BridgeInventoryCommand.main(Array(CommandLine.arguments.dropFirst(2))))
|
||||
}
|
||||
var env = try Environment.detect()
|
||||
try LoggingSystem.bootstrap(from: &env)
|
||||
// Vapor's console handler, wrapped so error lines can also reach the
|
||||
// error reporter. The wrapper sends nothing until `configure`
|
||||
// installs a reporter, which it does only when FN_SENTRY_DSN is set.
|
||||
try LoggingSystem.bootstrap(from: &env) { level in
|
||||
let console = Terminal()
|
||||
return { label in
|
||||
ReportingLogHandler(
|
||||
label: label,
|
||||
inner: ConsoleLogger(label: label, console: console, level: level))
|
||||
}
|
||||
}
|
||||
|
||||
let app = try await Application.make(env)
|
||||
do {
|
||||
@@ -87,9 +97,15 @@ func configure(_ app: Application) async throws {
|
||||
// Order matters and is easy to get backwards: `use` appends, and the FIRST
|
||||
// middleware added is the OUTERMOST.
|
||||
app.middleware = .init()
|
||||
// Error reporting, off unless FN_SENTRY_DSN is set. Outermost, so it sees
|
||||
// the status every other middleware settled on. See ErrorReporting.swift
|
||||
// for the allowlist of what an event may carry.
|
||||
let reporter = try errorReporter(for: app)
|
||||
if let reporter { app.middleware.use(ErrorReportingMiddleware(reporter: reporter)) }
|
||||
app.middleware.use(SecurityHeadersMiddleware())
|
||||
app.middleware.use(HTMLNotFoundMiddleware())
|
||||
app.middleware.use(ErrorMiddleware.default(environment: app.environment))
|
||||
if reporter != nil { app.middleware.use(ErrorTypeCaptureMiddleware()) }
|
||||
app.middleware.use(WireErrorMiddleware())
|
||||
|
||||
// SQLite by default: one file, no second process, which is what makes "run
|
||||
@@ -1613,6 +1629,34 @@ func clientIP(_ request: Request) -> String {
|
||||
return peer
|
||||
}
|
||||
|
||||
/// The reporter for this process when FN_SENTRY_DSN is set, installed for
|
||||
/// log lines written outside a request and removed at shutdown. Nil, and
|
||||
/// nothing installed, when it is not.
|
||||
func errorReporter(for app: Application) throws -> ErrorReporter? {
|
||||
let dsn: SentryDSN?
|
||||
do {
|
||||
dsn = try ErrorReporting.dsnFromEnvironment()
|
||||
} catch {
|
||||
app.logger.critical("configuration: \(error)")
|
||||
throw error
|
||||
}
|
||||
guard let dsn else { return nil }
|
||||
let reporter = ErrorReporter(
|
||||
dsn: dsn, environment: app.environment.name,
|
||||
transport: VaporClientTransport(
|
||||
client: app.client, logger: Logger(label: "flamenet.error-reporter")))
|
||||
ErrorReporting.install(reporter)
|
||||
app.lifecycle.use(ErrorReporterLifecycle())
|
||||
app.logger.notice("error reporting: on")
|
||||
return reporter
|
||||
}
|
||||
|
||||
private struct ErrorReporterLifecycle: LifecycleHandler {
|
||||
func shutdown(_ application: Application) {
|
||||
ErrorReporting.install(nil)
|
||||
}
|
||||
}
|
||||
|
||||
/// Renders `WireError` as the JSON body clients already parse.
|
||||
struct WireErrorMiddleware: AsyncMiddleware {
|
||||
func respond(to request: Request, chainingTo next: any AsyncResponder) async throws -> Response
|
||||
@@ -1625,12 +1669,7 @@ struct WireErrorMiddleware: AsyncMiddleware {
|
||||
// without this line, and tonight proved that is the exact moment
|
||||
// someone is reading these logs.
|
||||
if e.httpStatus == .unauthorized {
|
||||
let masked = request.url.path.split(separator: "/").map { seg -> String in
|
||||
let s = String(seg)
|
||||
let isNumeric = s.allSatisfy(\.isNumber)
|
||||
let isUUIDish = s.count >= 16 && s.allSatisfy { $0.isHexDigit || $0 == "-" }
|
||||
return (isNumeric || isUUIDish) ? ":id" : s
|
||||
}.joined(separator: "/")
|
||||
let masked = PathMask.mask(request.url.path)
|
||||
request.logger.notice(
|
||||
"refused \(request.method) /\(masked): \(e.code) \(e.message)")
|
||||
}
|
||||
|
||||
@@ -0,0 +1,727 @@
|
||||
import Crypto
|
||||
import Dispatch
|
||||
import Foundation
|
||||
import Logging
|
||||
import NIOCore
|
||||
import Vapor
|
||||
|
||||
// Error reporting to an operator-run Sentry-protocol collector (GlitchTip).
|
||||
//
|
||||
// Off unless FN_SENTRY_DSN is set. When it is, errors and criticals, and every
|
||||
// response with a 5xx status, become one event each. Warnings stay on stdout.
|
||||
// Info and debug are never sent, because the `debug` level is the one that
|
||||
// writes request URLs and a protocol URL names a device.
|
||||
//
|
||||
// What an event carries is an allowlist, built here and nowhere else: level,
|
||||
// the scrubbed message, the error's type name, the route TEMPLATE
|
||||
// (`/e2e/devices/:deviceID`, never the path that was asked for), the method,
|
||||
// the status, a fingerprint, and the source location of the log call. No
|
||||
// headers, no body, no query, no address, no account, no device, no user
|
||||
// block, no breadcrumbs, no logger metadata. Vapor's ErrorMiddleware attaches
|
||||
// the full URL and the User-Agent as metadata to every error it logs; the
|
||||
// metadata is dropped here, unread.
|
||||
|
||||
// MARK: - DSN
|
||||
|
||||
/// `scheme://<public key>@host[:port][/prefix]/<project id>`.
|
||||
struct SentryDSN: Sendable, Equatable {
|
||||
let publicKey: String
|
||||
let envelopeURL: String
|
||||
|
||||
init?(_ raw: String) {
|
||||
let trimmed = raw.trimmingCharacters(in: .whitespacesAndNewlines)
|
||||
guard let parts = URLComponents(string: trimmed),
|
||||
let scheme = parts.scheme?.lowercased(), scheme == "http" || scheme == "https",
|
||||
let key = parts.user, !key.isEmpty,
|
||||
let host = parts.host, !host.isEmpty
|
||||
else { return nil }
|
||||
var segments = parts.path.split(separator: "/").map(String.init)
|
||||
guard let project = segments.popLast(), !project.isEmpty,
|
||||
project.allSatisfy(\.isNumber)
|
||||
else { return nil }
|
||||
let prefix = segments.isEmpty ? "" : "/" + segments.joined(separator: "/")
|
||||
let port = parts.port.map { ":\($0)" } ?? ""
|
||||
self.publicKey = key
|
||||
self.envelopeURL = "\(scheme)://\(host)\(port)\(prefix)/api/\(project)/envelope/"
|
||||
}
|
||||
|
||||
var authHeader: String {
|
||||
"Sentry sentry_version=7, sentry_key=\(publicKey), sentry_client=flamenet-relay/1"
|
||||
}
|
||||
}
|
||||
|
||||
// MARK: - Path masking
|
||||
|
||||
/// The masking WireErrorMiddleware applies to a refused request's path before
|
||||
/// it is logged: numeric segments and UUID-like segments become `:id`.
|
||||
enum PathMask {
|
||||
static func mask(_ path: String) -> String {
|
||||
path.split(separator: "/").map { seg -> String in
|
||||
let s = String(seg)
|
||||
let isNumeric = s.allSatisfy(\.isNumber)
|
||||
let isUUIDish = s.count >= 16 && s.allSatisfy { $0.isHexDigit || $0 == "-" }
|
||||
return (isNumeric || isUUIDish) ? ":id" : s
|
||||
}.joined(separator: "/")
|
||||
}
|
||||
}
|
||||
|
||||
// MARK: - Scrubbing
|
||||
|
||||
/// Removes identifiers from free text before it leaves the process.
|
||||
///
|
||||
/// Shape rules alone cannot recognise a username, so the request path is
|
||||
/// handled by value first: every route parameter and query value of the
|
||||
/// request being reported is replaced wherever it appears, whatever it looks
|
||||
/// like. Everything after that works by shape and errs towards removing too
|
||||
/// much: a scrubbed timestamp costs a little debugging, a leaked device id
|
||||
/// costs the promise on /metadata.
|
||||
enum ReportScrubber {
|
||||
static let maxLength = 512
|
||||
|
||||
private static func regex(_ pattern: String) -> NSRegularExpression {
|
||||
// The patterns are constants; a bad one is a programming error that
|
||||
// every test run would hit.
|
||||
try! NSRegularExpression(pattern: pattern, options: [])
|
||||
}
|
||||
|
||||
// NSRegularExpression is immutable after creation and documented as safe
|
||||
// to share between threads.
|
||||
nonisolated(unsafe) private static let url = regex(#"[A-Za-z][A-Za-z0-9+.-]*://[^\s"'<>]+"#)
|
||||
nonisolated(unsafe) private static let path = regex(
|
||||
#"(?<![A-Za-z0-9])(?:/[A-Za-z0-9._~%:@+=-]+){2,}/?"#)
|
||||
nonisolated(unsafe) private static let jwt = regex(
|
||||
#"eyJ[A-Za-z0-9_-]{4,}\.[A-Za-z0-9_-]{4,}\.[A-Za-z0-9_-]*"#)
|
||||
nonisolated(unsafe) private static let bearer = regex(
|
||||
#"(?i)\b(bearer|basic)\s+[A-Za-z0-9._~+/=-]+"#)
|
||||
nonisolated(unsafe) private static let secretPair = regex(
|
||||
#"(?i)\b([A-Za-z_-]*(?:token|secret|passw(?:or)?d|passphrase|key|auth|authorization|cookie|session|signature|sig|dsn|nonce|proof)[A-Za-z_-]*)("?\s*[=:]\s*"?)[^\s,;&"]+"#
|
||||
)
|
||||
nonisolated(unsafe) private static let sqlDetail = regex(#"\(([^()]*)\)=\(([^()]*)\)"#)
|
||||
nonisolated(unsafe) private static let email = regex(
|
||||
#"[A-Za-z0-9._%+-]+@[A-Za-z0-9.-]+\.[A-Za-z]{2,}"#)
|
||||
nonisolated(unsafe) private static let fnid = regex(#"fnid:[A-Za-z0-9_=-]+"#)
|
||||
nonisolated(unsafe) private static let uuid = regex(
|
||||
#"[0-9A-Fa-f]{8}-[0-9A-Fa-f]{4}-[0-9A-Fa-f]{4}-[0-9A-Fa-f]{4}-[0-9A-Fa-f]{12}"#)
|
||||
nonisolated(unsafe) private static let ipv4 = regex(
|
||||
#"(?<![\d.])(?:\d{1,3}\.){3}\d{1,3}(?::\d{1,5})?(?![\d.])"#)
|
||||
// Any run of hex digits and colons holding at least two colons. Catches
|
||||
// every IPv6 form, and also clock times, which is the cheaper mistake.
|
||||
nonisolated(unsafe) private static let ipv6 = regex(
|
||||
#"(?<![0-9A-Za-z:])(?=[0-9A-Fa-f:]*:[0-9A-Fa-f]*:)[0-9A-Fa-f:]{2,39}(?![0-9A-Za-z:])"#)
|
||||
nonisolated(unsafe) private static let phone = regex(#"\+\d[\d\s().-]{6,}\d"#)
|
||||
nonisolated(unsafe) private static let hex = regex(#"(?<![A-Za-z0-9])[0-9A-Fa-f]{16,}(?![A-Za-z0-9])"#)
|
||||
nonisolated(unsafe) private static let tokenish = regex(#"[A-Za-z0-9+/_=-]{16,}"#)
|
||||
nonisolated(unsafe) private static let longNumber = regex(#"(?<!\d)\d{7,}(?!\d)"#)
|
||||
nonisolated(unsafe) private static let keyword = regex(
|
||||
#"(?i)\b(device|devices|attachment|account|user|username|handle|token|report|recipient|sender|peer|conversation|group|member|id)(\s+|\s*[#=:]\s*)([^\s,;()<]+)"#
|
||||
)
|
||||
// Upper-case env names and lower-case snake identifiers are kept: a
|
||||
// random token of 16 or more characters falls into either shape with
|
||||
// negligible probability, and the names are what make a message useful.
|
||||
nonisolated(unsafe) private static let readableName = regex(
|
||||
#"^(?:[A-Z]+(?:_[A-Z]+)+|[a-z]+(?:_[a-z]+)+)$"#)
|
||||
|
||||
/// - Parameter values: strings known to identify somebody in this
|
||||
/// request (route parameters, query values). Replaced first, exactly.
|
||||
static func scrub(_ text: String, replacing values: [(name: String, value: String)] = [])
|
||||
-> String
|
||||
{
|
||||
var s = text
|
||||
// Longest first, so a value that contains another is not split.
|
||||
for (name, value) in values.sorted(by: { $0.value.count > $1.value.count })
|
||||
where value.count >= 3 {
|
||||
s = s.replacingOccurrences(of: value, with: ":\(name)")
|
||||
}
|
||||
s = replace(url, in: s, with: "<url>")
|
||||
s = transform(path, in: s) { PathMask.mask($0).isEmpty ? $0 : "/" + PathMask.mask($0) }
|
||||
s = replace(jwt, in: s, with: "<jwt>")
|
||||
s = replace(bearer, in: s, with: "$1 <redacted>")
|
||||
s = replace(sqlDetail, in: s, with: "($1)=(<redacted>)")
|
||||
s = replace(secretPair, in: s, with: "$1$2<redacted>")
|
||||
s = replace(email, in: s, with: "<email>")
|
||||
s = replace(fnid, in: s, with: "fnid:<id>")
|
||||
s = replace(uuid, in: s, with: "<uuid>")
|
||||
s = replace(ipv4, in: s, with: "<ip>")
|
||||
s = replace(ipv6, in: s, with: "<ip>")
|
||||
s = replace(phone, in: s, with: "<phone>")
|
||||
s = replace(hex, in: s, with: "<hex>")
|
||||
s = transform(tokenish, in: s) { run in
|
||||
looksLikeToken(run) ? "<token>" : run
|
||||
}
|
||||
s = replace(longNumber, in: s, with: "<n>")
|
||||
s = transformGroups(keyword, in: s) { word, sep, value in
|
||||
looksLikeIdentifier(value) ? "\(word)\(sep)<id>" : nil
|
||||
}
|
||||
if s.count > maxLength {
|
||||
s = String(s.prefix(maxLength)) + "..."
|
||||
}
|
||||
return s
|
||||
}
|
||||
|
||||
/// `/e2e/devices/:deviceID` from the matched route, never from the URL.
|
||||
static func routeTemplate(_ route: Route?) -> String {
|
||||
guard let route else { return "<unmatched>" }
|
||||
return "/" + route.path.map(\.description).joined(separator: "/")
|
||||
}
|
||||
|
||||
private static func looksLikeToken(_ run: String) -> Bool {
|
||||
let whole = NSRange(run.startIndex..., in: run)
|
||||
if readableName.firstMatch(in: run, range: whole) != nil { return false }
|
||||
if run.contains(where: \.isNumber) { return true }
|
||||
if run.contains(where: { "+/=_-".contains($0) }) { return true }
|
||||
return run.filter(\.isUppercase).count >= 5
|
||||
}
|
||||
|
||||
private static func looksLikeIdentifier(_ value: String) -> Bool {
|
||||
if value.hasPrefix("<") || value.hasPrefix(":") { return false }
|
||||
if value.contains(where: \.isNumber) { return true }
|
||||
if value.contains(where: { "-_:@./=+".contains($0) }) { return true }
|
||||
return value.count >= 20
|
||||
}
|
||||
|
||||
private static func replace(_ re: NSRegularExpression, in s: String, with template: String)
|
||||
-> String
|
||||
{
|
||||
re.stringByReplacingMatches(
|
||||
in: s, range: NSRange(s.startIndex..., in: s), withTemplate: template)
|
||||
}
|
||||
|
||||
private static func transform(
|
||||
_ re: NSRegularExpression, in s: String, _ f: (String) -> String
|
||||
) -> String {
|
||||
var out = s
|
||||
for m in re.matches(in: s, range: NSRange(s.startIndex..., in: s)).reversed() {
|
||||
guard let r = Range(m.range, in: s), let target = Range(m.range, in: out) else {
|
||||
continue
|
||||
}
|
||||
out.replaceSubrange(target, with: f(String(s[r])))
|
||||
}
|
||||
return out
|
||||
}
|
||||
|
||||
private static func transformGroups(
|
||||
_ re: NSRegularExpression, in s: String,
|
||||
_ f: (String, String, String) -> String?
|
||||
) -> String {
|
||||
var out = s
|
||||
for m in re.matches(in: s, range: NSRange(s.startIndex..., in: s)).reversed() {
|
||||
guard let a = Range(m.range(at: 1), in: s),
|
||||
let b = Range(m.range(at: 2), in: s),
|
||||
let c = Range(m.range(at: 3), in: s),
|
||||
let replacement = f(String(s[a]), String(s[b]), String(s[c])),
|
||||
let target = Range(m.range, in: out)
|
||||
else { continue }
|
||||
out.replaceSubrange(target, with: replacement)
|
||||
}
|
||||
return out
|
||||
}
|
||||
}
|
||||
|
||||
// MARK: - Events
|
||||
|
||||
struct ReportEvent: Sendable, Equatable {
|
||||
var level: Logger.Level
|
||||
/// Already scrubbed.
|
||||
var message: String
|
||||
var errorType: String? = nil
|
||||
var route: String? = nil
|
||||
var method: String? = nil
|
||||
var status: UInt? = nil
|
||||
var file: String? = nil
|
||||
var function: String? = nil
|
||||
var line: UInt? = nil
|
||||
var logger: String? = nil
|
||||
|
||||
/// Groups repeats of one fault: digits are collapsed so that a count in
|
||||
/// the message does not split an issue in two.
|
||||
var fingerprint: String {
|
||||
let collapsed = message.replacingOccurrences(
|
||||
of: #"\d+"#, with: "#", options: .regularExpression)
|
||||
// Built one part at a time: as a single array literal of optional
|
||||
// coalescing it is past what the Linux compiler will type-check.
|
||||
var parts: [String] = ["\(level)"]
|
||||
parts.append(errorType ?? "")
|
||||
parts.append(route ?? "")
|
||||
parts.append(method ?? "")
|
||||
parts.append(status.map { "\($0 / 100)xx" } ?? "")
|
||||
parts.append(file ?? "")
|
||||
parts.append(line.map { String($0) } ?? "")
|
||||
parts.append(collapsed)
|
||||
let digest = SHA256.hash(data: Data(parts.joined(separator: "|").utf8))
|
||||
return digest.prefix(8).map { byte -> String in
|
||||
let hex = String(byte, radix: 16)
|
||||
return hex.count == 1 ? "0" + hex : hex
|
||||
}.joined()
|
||||
}
|
||||
}
|
||||
|
||||
/// The only place an event becomes bytes. Every field written here is listed
|
||||
/// at the top of this file; adding one is a change to what /metadata means.
|
||||
enum SentryEnvelope {
|
||||
private struct Header: Encodable {
|
||||
let event_id: String
|
||||
let sent_at: String
|
||||
}
|
||||
private struct ItemHeader: Encodable {
|
||||
let type = "event"
|
||||
let content_type = "application/json"
|
||||
let length: Int
|
||||
}
|
||||
private struct Frame: Encodable {
|
||||
let filename: String?
|
||||
let function: String?
|
||||
let lineno: UInt?
|
||||
let in_app = true
|
||||
}
|
||||
private struct Stacktrace: Encodable { let frames: [Frame] }
|
||||
private struct ExceptionValue: Encodable {
|
||||
let type: String
|
||||
let value: String
|
||||
let stacktrace: Stacktrace?
|
||||
}
|
||||
private struct Exception: Encodable { let values: [ExceptionValue] }
|
||||
private struct Message: Encodable { let formatted: String }
|
||||
private struct Payload: Encodable {
|
||||
let event_id: String
|
||||
let timestamp: String
|
||||
let platform = "other"
|
||||
let level: String
|
||||
let logger: String?
|
||||
let environment: String
|
||||
let message: Message
|
||||
let exception: Exception?
|
||||
let tags: [String: String]
|
||||
let fingerprint: [String]
|
||||
}
|
||||
|
||||
static func sentryLevel(_ level: Logger.Level) -> String {
|
||||
switch level {
|
||||
case .critical: return "fatal"
|
||||
case .error: return "error"
|
||||
case .warning: return "warning"
|
||||
case .notice, .info: return "info"
|
||||
case .debug, .trace: return "debug"
|
||||
}
|
||||
}
|
||||
|
||||
static func encode(
|
||||
_ event: ReportEvent, environment: String, eventID: String = UUID().uuidString,
|
||||
now: Date = Date()
|
||||
) throws -> Data {
|
||||
let id = eventID.replacingOccurrences(of: "-", with: "").lowercased()
|
||||
let iso = ISO8601DateFormatter()
|
||||
iso.formatOptions = [.withInternetDateTime, .withFractionalSeconds]
|
||||
let stamp = iso.string(from: now)
|
||||
|
||||
var tags: [String: String] = [:]
|
||||
if let route = event.route { tags["route"] = route }
|
||||
if let method = event.method { tags["method"] = method }
|
||||
if let status = event.status { tags["status"] = String(status) }
|
||||
|
||||
let frame =
|
||||
event.file == nil && event.function == nil
|
||||
? nil : Stacktrace(frames: [Frame(filename: event.file, function: event.function, lineno: event.line)])
|
||||
let exception = Exception(values: [
|
||||
ExceptionValue(
|
||||
type: event.errorType ?? (event.status.map { "HTTP \($0)" } ?? "LoggedError"),
|
||||
value: event.message, stacktrace: frame)
|
||||
])
|
||||
let payload = Payload(
|
||||
event_id: id, timestamp: stamp, level: sentryLevel(event.level),
|
||||
logger: event.logger, environment: environment,
|
||||
message: Message(formatted: event.message), exception: exception,
|
||||
tags: tags, fingerprint: [event.fingerprint])
|
||||
|
||||
let encoder = JSONEncoder()
|
||||
encoder.outputFormatting = [.sortedKeys, .withoutEscapingSlashes]
|
||||
let body = try encoder.encode(payload)
|
||||
var out = Data()
|
||||
out.append(try encoder.encode(Header(event_id: id, sent_at: stamp)))
|
||||
out.append(0x0A)
|
||||
out.append(try encoder.encode(ItemHeader(length: body.count)))
|
||||
out.append(0x0A)
|
||||
out.append(body)
|
||||
out.append(0x0A)
|
||||
return out
|
||||
}
|
||||
}
|
||||
|
||||
// MARK: - Transport
|
||||
|
||||
protocol ErrorTransport: Sendable {
|
||||
/// Fire and forget. Must not throw and must not retry.
|
||||
func post(url: String, headers: [(String, String)], body: Data) async
|
||||
}
|
||||
|
||||
/// Vapor's client, with a 2 second ceiling per send.
|
||||
struct VaporClientTransport: ErrorTransport {
|
||||
let client: any Client
|
||||
let logger: Logger
|
||||
|
||||
func post(url: String, headers: [(String, String)], body: Data) async {
|
||||
var h = HTTPHeaders()
|
||||
for (name, value) in headers { h.add(name: name, value: value) }
|
||||
var buffer = ByteBufferAllocator().buffer(capacity: body.count)
|
||||
buffer.writeBytes(body)
|
||||
let request = ClientRequest(
|
||||
method: .POST, url: URI(string: url), headers: h, body: buffer,
|
||||
timeout: .seconds(2))
|
||||
do {
|
||||
let response = try await client.send(request)
|
||||
if response.status.code >= 300 {
|
||||
ErrorReporter.noteFailure("collector answered \(response.status.code)", logger)
|
||||
}
|
||||
} catch {
|
||||
// The error text can name the collector's address, which is
|
||||
// the operator's own; it is still kept to the type.
|
||||
ErrorReporter.noteFailure("send failed: \(type(of: error))", logger)
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
// MARK: - Reporter
|
||||
|
||||
/// Rate limit, dedupe and dispatch. Thread-safe; every entry point returns
|
||||
/// at once and sends on a detached task.
|
||||
final class ErrorReporter: @unchecked Sendable {
|
||||
let dsn: SentryDSN
|
||||
let environment: String
|
||||
private let transport: any ErrorTransport
|
||||
private let now: @Sendable () -> Date
|
||||
|
||||
private let capacity: Double
|
||||
private let refillPerSecond: Double
|
||||
private let dedupeWindow: TimeInterval
|
||||
private let maxRemembered = 1000
|
||||
|
||||
private let lock = NSLock()
|
||||
private var tokens: Double
|
||||
private var lastRefill: Date
|
||||
private var recent: [String: Date] = [:]
|
||||
|
||||
init(
|
||||
dsn: SentryDSN, environment: String, transport: any ErrorTransport,
|
||||
perMinute: Int = 30, dedupeWindow: TimeInterval = 60,
|
||||
now: @escaping @Sendable () -> Date = { Date() }
|
||||
) {
|
||||
self.dsn = dsn
|
||||
self.environment = environment
|
||||
self.transport = transport
|
||||
self.now = now
|
||||
self.capacity = Double(perMinute)
|
||||
self.refillPerSecond = Double(perMinute) / 60
|
||||
self.dedupeWindow = dedupeWindow
|
||||
self.tokens = Double(perMinute)
|
||||
self.lastRefill = now()
|
||||
}
|
||||
|
||||
/// Whether the event was let through to be sent. Only `error` and
|
||||
/// `critical` ever are.
|
||||
@discardableResult
|
||||
func capture(_ event: ReportEvent) -> Bool {
|
||||
guard event.level >= .error else { return false }
|
||||
guard admit(event.fingerprint) else { return false }
|
||||
let body: Data
|
||||
do {
|
||||
body = try SentryEnvelope.encode(event, environment: environment, now: now())
|
||||
} catch {
|
||||
return false
|
||||
}
|
||||
let transport = self.transport
|
||||
let url = dsn.envelopeURL
|
||||
let headers = [
|
||||
("X-Sentry-Auth", dsn.authHeader),
|
||||
("Content-Type", "application/x-sentry-envelope"),
|
||||
]
|
||||
Task.detached {
|
||||
await transport.post(url: url, headers: headers, body: body)
|
||||
}
|
||||
return true
|
||||
}
|
||||
|
||||
private func admit(_ fingerprint: String) -> Bool {
|
||||
lock.lock()
|
||||
defer { lock.unlock() }
|
||||
let t = now()
|
||||
if let seen = recent[fingerprint], t.timeIntervalSince(seen) < dedupeWindow {
|
||||
return false
|
||||
}
|
||||
tokens = min(capacity, tokens + t.timeIntervalSince(lastRefill) * refillPerSecond)
|
||||
lastRefill = t
|
||||
guard tokens >= 1 else { return false }
|
||||
tokens -= 1
|
||||
if recent.count >= maxRemembered {
|
||||
recent = recent.filter { t.timeIntervalSince($0.value) < dedupeWindow }
|
||||
if recent.count >= maxRemembered { recent.removeAll() }
|
||||
}
|
||||
recent[fingerprint] = t
|
||||
return true
|
||||
}
|
||||
|
||||
// A failing collector is said once a minute on stdout at warning, which
|
||||
// never re-enters the reporter.
|
||||
nonisolated(unsafe) private static var lastFailureNote = Date.distantPast
|
||||
private static let failureLock = NSLock()
|
||||
|
||||
static func noteFailure(_ what: String, _ logger: Logger) {
|
||||
failureLock.lock()
|
||||
let t = Date()
|
||||
let due = t.timeIntervalSince(lastFailureNote) >= 60
|
||||
if due { lastFailureNote = t }
|
||||
failureLock.unlock()
|
||||
if due { logger.warning("error reporter: \(what)") }
|
||||
}
|
||||
}
|
||||
|
||||
// MARK: - Process-wide installation
|
||||
|
||||
/// The reporter for log lines written outside a request. Installed by
|
||||
/// `configure` when FN_SENTRY_DSN is set, removed at shutdown.
|
||||
enum ErrorReporting {
|
||||
private static let lock = NSLock()
|
||||
nonisolated(unsafe) private static var _installed: ErrorReporter?
|
||||
|
||||
static var installed: ErrorReporter? {
|
||||
lock.lock()
|
||||
defer { lock.unlock() }
|
||||
return _installed
|
||||
}
|
||||
|
||||
static func install(_ reporter: ErrorReporter?) {
|
||||
lock.lock()
|
||||
_installed = reporter
|
||||
lock.unlock()
|
||||
}
|
||||
|
||||
/// Reads FN_SENTRY_DSN. Unset or empty: nil, nothing is sent. Set but
|
||||
/// unparseable: refuse to start, like every other malformed setting.
|
||||
static func dsnFromEnvironment(
|
||||
_ env: [String: String] = ProcessInfo.processInfo.environment
|
||||
) throws -> SentryDSN? {
|
||||
guard let raw = env["FN_SENTRY_DSN"]?.trimmingCharacters(in: .whitespaces),
|
||||
!raw.isEmpty
|
||||
else { return nil }
|
||||
guard let dsn = SentryDSN(raw) else {
|
||||
throw Abort(
|
||||
.internalServerError,
|
||||
reason: "FN_SENTRY_DSN is not a DSN (scheme://key@host/project)")
|
||||
}
|
||||
return dsn
|
||||
}
|
||||
}
|
||||
|
||||
// MARK: - Per-request context
|
||||
|
||||
/// Collects the first error logged while one request is in flight, so the
|
||||
/// request produces one event carrying its route and status rather than one
|
||||
/// per log line. Carried on the request's logger as metadata that the
|
||||
/// reporting handler intercepts and never forwards.
|
||||
final class RequestReportContext: @unchecked Sendable, CustomStringConvertible {
|
||||
static let metadataKey = "fn-report-context"
|
||||
|
||||
struct StorageKey: Vapor.StorageKey {
|
||||
typealias Value = RequestReportContext
|
||||
}
|
||||
|
||||
private let lock = NSLock()
|
||||
private var _level: Logger.Level?
|
||||
private var _message: String?
|
||||
private var _file: String?
|
||||
private var _function: String?
|
||||
private var _line: UInt?
|
||||
private var _errorType: String?
|
||||
|
||||
var description: String { "" }
|
||||
|
||||
func record(level: Logger.Level, message: String, file: String, function: String, line: UInt)
|
||||
{
|
||||
lock.lock()
|
||||
defer { lock.unlock() }
|
||||
if let existing = _level {
|
||||
if level > existing { _level = level }
|
||||
return
|
||||
}
|
||||
_level = level
|
||||
_message = message
|
||||
_file = file
|
||||
_function = function
|
||||
_line = line
|
||||
}
|
||||
|
||||
func noteErrorType(_ name: String) {
|
||||
lock.lock()
|
||||
if _errorType == nil { _errorType = name }
|
||||
lock.unlock()
|
||||
}
|
||||
|
||||
var snapshot:
|
||||
(
|
||||
level: Logger.Level?, message: String?, file: String?, function: String?,
|
||||
line: UInt?, errorType: String?
|
||||
)
|
||||
{
|
||||
lock.lock()
|
||||
defer { lock.unlock() }
|
||||
return (_level, _message, _file, _function, _line, _errorType)
|
||||
}
|
||||
}
|
||||
|
||||
// MARK: - Log handler
|
||||
|
||||
/// Wraps the stdout handler. Forwards everything to it unchanged, except the
|
||||
/// request-context marker, and hands error and critical lines to the
|
||||
/// reporter: to the request's context when there is one, straight to the
|
||||
/// process reporter when not.
|
||||
struct ReportingLogHandler: LogHandler {
|
||||
var inner: any LogHandler
|
||||
let label: String
|
||||
let reporter: @Sendable () -> ErrorReporter?
|
||||
var context: RequestReportContext?
|
||||
|
||||
init(
|
||||
label: String, inner: any LogHandler,
|
||||
reporter: @escaping @Sendable () -> ErrorReporter? = { ErrorReporting.installed }
|
||||
) {
|
||||
self.label = label
|
||||
self.inner = inner
|
||||
self.reporter = reporter
|
||||
self.logLevel = inner.logLevel
|
||||
}
|
||||
|
||||
// Kept here as well as passed down: a handler is free to ignore the
|
||||
// level it is given (SwiftLog's no-op handler always answers critical),
|
||||
// and the Logger gates on what this property returns.
|
||||
var logLevel: Logger.Level {
|
||||
didSet { inner.logLevel = logLevel }
|
||||
}
|
||||
|
||||
var metadata: Logger.Metadata {
|
||||
get { inner.metadata }
|
||||
set { inner.metadata = newValue }
|
||||
}
|
||||
|
||||
subscript(metadataKey key: String) -> Logger.Metadata.Value? {
|
||||
get {
|
||||
if key == RequestReportContext.metadataKey { return context.map { .stringConvertible($0) } }
|
||||
return inner[metadataKey: key]
|
||||
}
|
||||
set {
|
||||
if key == RequestReportContext.metadataKey {
|
||||
if case .stringConvertible(let value)? = newValue {
|
||||
context = value as? RequestReportContext
|
||||
} else {
|
||||
context = nil
|
||||
}
|
||||
return
|
||||
}
|
||||
inner[metadataKey: key] = newValue
|
||||
}
|
||||
}
|
||||
|
||||
func log(
|
||||
level: Logger.Level, message: Logger.Message, metadata: Logger.Metadata?,
|
||||
source: String, file: String, function: String, line: UInt
|
||||
) {
|
||||
inner.log(
|
||||
level: level, message: message, metadata: metadata, source: source, file: file,
|
||||
function: function, line: line)
|
||||
guard level >= .error else { return }
|
||||
if let context {
|
||||
// Scrubbed later, when the request's own values are known.
|
||||
context.record(
|
||||
level: level, message: message.description, file: file, function: function,
|
||||
line: line)
|
||||
return
|
||||
}
|
||||
guard let reporter = reporter() else { return }
|
||||
reporter.capture(
|
||||
ReportEvent(
|
||||
level: level, message: ReportScrubber.scrub(message.description),
|
||||
file: file, function: function, line: line, logger: label))
|
||||
}
|
||||
}
|
||||
|
||||
// MARK: - Middleware
|
||||
|
||||
/// Outermost: owns the request's context and sends its one event.
|
||||
struct ErrorReportingMiddleware: AsyncMiddleware {
|
||||
let reporter: ErrorReporter
|
||||
|
||||
func respond(to request: Request, chainingTo next: any AsyncResponder) async throws -> Response
|
||||
{
|
||||
let context = RequestReportContext()
|
||||
request.storage[RequestReportContext.StorageKey.self] = context
|
||||
request.logger[metadataKey: RequestReportContext.metadataKey] = .stringConvertible(context)
|
||||
do {
|
||||
let response = try await next.respond(to: request)
|
||||
finish(request, context, status: response.status.code)
|
||||
return response
|
||||
} catch {
|
||||
context.noteErrorType(String(describing: type(of: error)))
|
||||
finish(request, context, status: 500)
|
||||
throw error
|
||||
}
|
||||
}
|
||||
|
||||
private func finish(_ request: Request, _ context: RequestReportContext, status: UInt) {
|
||||
request.logger[metadataKey: RequestReportContext.metadataKey] = nil
|
||||
request.storage[RequestReportContext.StorageKey.self] = nil
|
||||
let seen = context.snapshot
|
||||
guard status >= 500 || seen.level != nil else { return }
|
||||
let values = Self.identifyingValues(request)
|
||||
let message =
|
||||
seen.message.map { ReportScrubber.scrub($0, replacing: values) }
|
||||
?? "HTTP \(status)"
|
||||
reporter.capture(
|
||||
ReportEvent(
|
||||
level: max(seen.level ?? .error, .error), message: message,
|
||||
errorType: seen.errorType, route: ReportScrubber.routeTemplate(request.route),
|
||||
method: request.method.rawValue, status: status, file: seen.file,
|
||||
function: seen.function, line: seen.line, logger: "codes.vapor.request"))
|
||||
}
|
||||
|
||||
/// Route parameters and query values of this request: removed from the
|
||||
/// message by value, so a username is caught even though nothing about
|
||||
/// its shape gives it away.
|
||||
static func identifyingValues(_ request: Request) -> [(name: String, value: String)] {
|
||||
var out: [(name: String, value: String)] = []
|
||||
for name in request.parameters.allNames {
|
||||
if let v = request.parameters.get(name) {
|
||||
out.append((name, v))
|
||||
if let decoded = v.removingPercentEncoding, decoded != v {
|
||||
out.append((name, decoded))
|
||||
}
|
||||
}
|
||||
}
|
||||
for v in request.parameters.getCatchall() { out.append(("path", v)) }
|
||||
if let query = request.url.query {
|
||||
for pair in query.split(separator: "&") {
|
||||
let kv = pair.split(separator: "=", maxSplits: 1).map(String.init)
|
||||
guard kv.count == 2 else { continue }
|
||||
out.append((kv[0].filter { $0.isLetter || $0 == "_" }, kv[1]))
|
||||
if let decoded = kv[1].removingPercentEncoding, decoded != kv[1] {
|
||||
out.append((kv[0].filter { $0.isLetter || $0 == "_" }, decoded))
|
||||
}
|
||||
}
|
||||
}
|
||||
// The path as asked for, in case a handler logged it whole.
|
||||
let path = request.url.path
|
||||
if path.count > 1 { out.append(("path", path)) }
|
||||
return out
|
||||
}
|
||||
}
|
||||
|
||||
/// Innermost: notes the type of an error a handler threw before
|
||||
/// ErrorMiddleware turns it into a response.
|
||||
struct ErrorTypeCaptureMiddleware: AsyncMiddleware {
|
||||
func respond(to request: Request, chainingTo next: any AsyncResponder) async throws -> Response
|
||||
{
|
||||
do {
|
||||
return try await next.respond(to: request)
|
||||
} catch {
|
||||
request.storage[RequestReportContext.StorageKey.self]?
|
||||
.noteErrorType(String(describing: type(of: error)))
|
||||
throw error
|
||||
}
|
||||
}
|
||||
}
|
||||
@@ -0,0 +1,411 @@
|
||||
import Foundation
|
||||
import Logging
|
||||
import Testing
|
||||
import Vapor
|
||||
import VaporTesting
|
||||
|
||||
@testable import FlamenetRelay
|
||||
|
||||
/// Error reporting to the operator's GlitchTip. /metadata says the relay's
|
||||
/// own logs name no account, device or address, so anything that leaves the
|
||||
/// process must hold to the same line. These tests are what holds it.
|
||||
@Suite("error reporting")
|
||||
struct ErrorReportingTests {
|
||||
|
||||
// Values a careless log line could carry.
|
||||
static let accountID = "3f2a9c1e-7b4d-4e8a-9f10-2c3d4e5f6a7b"
|
||||
static let fnid = "fnid:mfrggzdfmztwq2lknnwg23tpobyxe43u"
|
||||
static let userID = "user 48213"
|
||||
static let ipv4 = "203.0.113.77"
|
||||
static let ipv6 = "2001:db8:85a3::8a2e:370:7334"
|
||||
static let jwt =
|
||||
"eyJhbGciOiJFZERTQSJ9.eyJzdWIiOiI0ODIxMyIsImF1ZCI6InJlbGF5In0.c2lnbmF0dXJlLWJ5dGVzLWhlcmU"
|
||||
static let bearer = "Bearer q8ZtR3vLx0PmN5sKd7WbYc2HjF9gA4eU"
|
||||
static let rawToken = "Zx81_mQp2LrT9vNw4KsY6dHa"
|
||||
static let email = "someone@example.org"
|
||||
static let phone = "+1 (402) 555-0137"
|
||||
|
||||
static var everything: String {
|
||||
"account \(accountID) \(fnid) \(userID) from \(ipv4) and [\(ipv6)]:443 "
|
||||
+ "authorization: \(bearer) token=\(rawToken) jwt \(jwt) "
|
||||
+ "mail \(email) phone \(phone)"
|
||||
}
|
||||
|
||||
static let secrets = [
|
||||
accountID, "mfrggzdfmztwq2lknnwg23tpobyxe43u", "48213", ipv4, "2001:db8", "8a2e:370:7334",
|
||||
jwt, "eyJhbGciOiJFZERTQSJ9", "q8ZtR3vLx0PmN5sKd7WbYc2HjF9gA4eU", rawToken, email,
|
||||
"555-0137",
|
||||
]
|
||||
|
||||
static let dsn = SentryDSN("http://publickey123@glitchtip-relay:8000/1")!
|
||||
|
||||
// MARK: - Scrubbing
|
||||
|
||||
@Test("an account id, an IP address and a token are all replaced")
|
||||
func accountIPAndTokenAreScrubbed() {
|
||||
let line =
|
||||
"send failed for account \(Self.accountID) from \(Self.ipv4) with token=\(Self.rawToken)"
|
||||
let out = ReportScrubber.scrub(line)
|
||||
#expect(!out.contains(Self.accountID))
|
||||
#expect(!out.contains(Self.ipv4))
|
||||
#expect(!out.contains(Self.rawToken))
|
||||
#expect(out.contains("<uuid>") || out.contains("<id>"))
|
||||
#expect(out.contains("<ip>"))
|
||||
#expect(out.contains("<redacted>"))
|
||||
}
|
||||
|
||||
@Test("every identifier shape in one line is removed")
|
||||
func everyShapeIsScrubbed() {
|
||||
let out = ReportScrubber.scrub(Self.everything)
|
||||
for secret in Self.secrets {
|
||||
#expect(!out.contains(secret), "leaked \(secret) in: \(out)")
|
||||
}
|
||||
}
|
||||
|
||||
@Test("the relay's own complaint shapes lose their identifiers")
|
||||
func relayComplaintsAreScrubbed() {
|
||||
let device = "DEV-7f3a9b2c-alpha"
|
||||
let attachment = "a1B2c3D4e5F6g7H8i9J0kLmN"
|
||||
let lines = [
|
||||
"device \(device) changed its identity key without a continuity proof.",
|
||||
"attachment \(attachment) is truncated: indexed 1200 bytes, found 600.",
|
||||
"report 991 filed but could not be mailed: connection refused",
|
||||
"storage failure: PSQLError(detail: Key (username)=(alice) already exists.)",
|
||||
"refused GET /e2e/devices/\(Self.accountID)/prekeys: unauthorized",
|
||||
"fetch https://relay.example.com/e2e/keys/alice?device=\(device) failed",
|
||||
]
|
||||
let out = lines.map { ReportScrubber.scrub($0) }
|
||||
#expect(!out[0].contains(device))
|
||||
#expect(!out[1].contains(attachment))
|
||||
#expect(!out[2].contains("991"))
|
||||
#expect(!out[3].contains("alice"))
|
||||
#expect(!out[4].contains(Self.accountID))
|
||||
#expect(!out[5].contains("alice") && !out[5].contains(device))
|
||||
// Still says what went wrong.
|
||||
#expect(out[0].contains("changed its identity key"))
|
||||
#expect(out[1].contains("is truncated"))
|
||||
}
|
||||
|
||||
@Test("a request's own parameter values are removed whatever their shape")
|
||||
func parameterValuesAreRemovedByValue() {
|
||||
let out = ReportScrubber.scrub(
|
||||
"no prekeys left for alice on relay", replacing: [("handle", "alice")])
|
||||
#expect(!out.contains("alice"))
|
||||
#expect(out.contains(":handle"))
|
||||
}
|
||||
|
||||
@Test("configuration names stay readable")
|
||||
func configurationNamesSurvive() {
|
||||
let out = ReportScrubber.scrub(
|
||||
"FN_ISSUER_PRIVATE_KEY is not a 32-byte Ed25519 seed; sealed_inbound_only is off")
|
||||
#expect(out.contains("FN_ISSUER_PRIVATE_KEY"))
|
||||
#expect(out.contains("sealed_inbound_only"))
|
||||
}
|
||||
|
||||
@Test("a message is capped in length")
|
||||
func messageIsCapped() {
|
||||
let out = ReportScrubber.scrub(String(repeating: "word ", count: 400))
|
||||
#expect(out.count <= ReportScrubber.maxLength + 3)
|
||||
}
|
||||
|
||||
// MARK: - DSN
|
||||
|
||||
@Test("the DSN becomes the envelope endpoint and an auth header")
|
||||
func dsnParses() {
|
||||
#expect(Self.dsn.envelopeURL == "http://glitchtip-relay:8000/api/1/envelope/")
|
||||
#expect(Self.dsn.authHeader.contains("sentry_key=publickey123"))
|
||||
#expect(
|
||||
SentryDSN("https://k@bugs.example.com/prefix/7")?.envelopeURL
|
||||
== "https://bugs.example.com/prefix/api/7/envelope/")
|
||||
#expect(SentryDSN("not a dsn") == nil)
|
||||
#expect(SentryDSN("http://glitchtip-relay:8000/1") == nil) // no key
|
||||
#expect(SentryDSN("ftp://k@host/1") == nil)
|
||||
}
|
||||
|
||||
@Test("an unset or empty FN_SENTRY_DSN disables reporting; a bad one refuses to start")
|
||||
func dsnFromEnvironment() throws {
|
||||
#expect(try ErrorReporting.dsnFromEnvironment([:]) == nil)
|
||||
#expect(try ErrorReporting.dsnFromEnvironment(["FN_SENTRY_DSN": ""]) == nil)
|
||||
#expect(try ErrorReporting.dsnFromEnvironment(["FN_SENTRY_DSN": " "]) == nil)
|
||||
let parsed = try ErrorReporting.dsnFromEnvironment([
|
||||
"FN_SENTRY_DSN": "http://k@glitchtip-relay:8000/1"
|
||||
])
|
||||
#expect(parsed?.publicKey == "k")
|
||||
#expect(parsed?.envelopeURL == Self.dsn.envelopeURL)
|
||||
#expect(throws: (any Error).self) {
|
||||
try ErrorReporting.dsnFromEnvironment(["FN_SENTRY_DSN": "glitchtip"])
|
||||
}
|
||||
}
|
||||
|
||||
@Test("with FN_SENTRY_DSN unset, configure installs nothing and an error sends nothing")
|
||||
func unsetDSNSendsNothing() async throws {
|
||||
#expect(ProcessInfo.processInfo.environment["FN_SENTRY_DSN"] == nil)
|
||||
let app = try await Application.make(.testing)
|
||||
let reporter = try errorReporter(for: app)
|
||||
try await app.asyncShutdown()
|
||||
#expect(reporter == nil)
|
||||
#expect(ErrorReporting.installed == nil)
|
||||
|
||||
// The production handler asks for the installed reporter on every
|
||||
// error line. With none installed there is no transport to send on.
|
||||
let handler = ReportingLogHandler(label: "t", inner: SwiftLogNoOpLogHandler())
|
||||
#expect(handler.reporter() == nil)
|
||||
Logger(label: "t") { _ in handler }.critical("boom \(Self.everything)")
|
||||
#expect(ErrorReporting.installed == nil)
|
||||
}
|
||||
|
||||
// MARK: - Levels
|
||||
|
||||
@Test("info, debug, notice and warning never produce a send; error and critical do")
|
||||
func onlyErrorsAreSent() async throws {
|
||||
let transport = RecordingTransport()
|
||||
let reporter = ErrorReporter(dsn: Self.dsn, environment: "test", transport: transport)
|
||||
var logger = Logger(label: "t") { label in
|
||||
ReportingLogHandler(label: label, inner: SwiftLogNoOpLogHandler(), reporter: { reporter })
|
||||
}
|
||||
logger.logLevel = .trace
|
||||
logger.trace("trace line")
|
||||
logger.debug("debug line GET /e2e/devices/\(Self.accountID)")
|
||||
logger.info("info line")
|
||||
logger.notice("notice line")
|
||||
logger.warning("warning line")
|
||||
try await Task.sleep(for: .milliseconds(150))
|
||||
#expect(transport.count == 0)
|
||||
|
||||
logger.error("an error")
|
||||
logger.critical("a critical")
|
||||
try await transport.waitFor(2)
|
||||
#expect(transport.count == 2)
|
||||
#expect(!reporter.capture(ReportEvent(level: .warning, message: "w")))
|
||||
#expect(!reporter.capture(ReportEvent(level: .info, message: "i")))
|
||||
#expect(!reporter.capture(ReportEvent(level: .debug, message: "d")))
|
||||
}
|
||||
|
||||
// MARK: - Rate limit and dedupe
|
||||
|
||||
@Test("no more than 30 events a minute leave, and the bucket refills")
|
||||
func rateLimitHolds() {
|
||||
let clock = TestClock()
|
||||
let reporter = ErrorReporter(
|
||||
dsn: Self.dsn, environment: "test", transport: RecordingTransport(),
|
||||
now: { clock.now })
|
||||
// Distinct faults: digits collapse in the fingerprint, so vary letters.
|
||||
var distinct = 0
|
||||
let fresh = reporter
|
||||
for word in Self.words(45)
|
||||
where fresh.capture(ReportEvent(level: .error, message: "fault \(word)")) {
|
||||
distinct += 1
|
||||
}
|
||||
#expect(distinct == 30)
|
||||
clock.advance(4) // 0.5 a second: two more
|
||||
var later = 0
|
||||
for word in Self.words(10, offset: 100)
|
||||
where fresh.capture(ReportEvent(level: .error, message: "fault \(word)")) {
|
||||
later += 1
|
||||
}
|
||||
#expect(later == 2)
|
||||
}
|
||||
|
||||
@Test("the same fault twice inside 60 seconds is sent once")
|
||||
func dedupeHolds() {
|
||||
let clock = TestClock()
|
||||
let reporter = ErrorReporter(
|
||||
dsn: Self.dsn, environment: "test", transport: RecordingTransport(),
|
||||
now: { clock.now })
|
||||
let event = ReportEvent(
|
||||
level: .error, message: "redis unavailable after 3 tries", route: "/e2e/send")
|
||||
#expect(reporter.capture(event))
|
||||
#expect(!reporter.capture(event))
|
||||
// A different count is the same fault.
|
||||
#expect(
|
||||
!reporter.capture(
|
||||
ReportEvent(
|
||||
level: .error, message: "redis unavailable after 4 tries", route: "/e2e/send")))
|
||||
clock.advance(59)
|
||||
#expect(!reporter.capture(event))
|
||||
clock.advance(2)
|
||||
#expect(reporter.capture(event))
|
||||
}
|
||||
|
||||
// MARK: - The envelope
|
||||
|
||||
@Test("the envelope carries only the allowlisted fields")
|
||||
func envelopeIsAllowlisted() throws {
|
||||
let event = ReportEvent(
|
||||
level: .error, message: "storage failure", errorType: "PSQLError",
|
||||
route: "/e2e/devices/:deviceID", method: "POST", status: 500,
|
||||
file: "FlamenetRelay/Entrypoint.swift", function: "respond(to:chainingTo:)",
|
||||
line: 1652, logger: "codes.vapor.request")
|
||||
let data = try SentryEnvelope.encode(event, environment: "production")
|
||||
let lines = String(decoding: data, as: UTF8.self).split(separator: "\n")
|
||||
#expect(lines.count == 3)
|
||||
let header = try JSONSerialization.jsonObject(with: Data(lines[0].utf8)) as! [String: Any]
|
||||
#expect(Set(header.keys) == ["event_id", "sent_at"])
|
||||
let item = try JSONSerialization.jsonObject(with: Data(lines[1].utf8)) as! [String: Any]
|
||||
#expect(item["type"] as? String == "event")
|
||||
#expect(item["length"] as? Int == lines[2].utf8.count)
|
||||
let payload = try JSONSerialization.jsonObject(with: Data(lines[2].utf8)) as! [String: Any]
|
||||
#expect(
|
||||
Set(payload.keys) == [
|
||||
"event_id", "timestamp", "platform", "level", "logger", "environment", "message",
|
||||
"exception", "tags", "fingerprint",
|
||||
])
|
||||
let tags = payload["tags"] as! [String: String]
|
||||
#expect(tags == ["route": "/e2e/devices/:deviceID", "method": "POST", "status": "500"])
|
||||
#expect(payload["level"] as? String == "error")
|
||||
}
|
||||
|
||||
// MARK: - Through a real request
|
||||
|
||||
@Test("a request that logs identifiers and fails becomes one scrubbed event")
|
||||
func requestFailureIsOneScrubbedEvent() async throws {
|
||||
let transport = RecordingTransport()
|
||||
try await withReportingApp(transport) { app in
|
||||
try await app.testing().test(
|
||||
.GET, "/e2e/devices/\(Self.accountID)/keys/alice?token=\(Self.rawToken)",
|
||||
headers: ["X-Forwarded-For": Self.ipv4, "Authorization": Self.bearer]
|
||||
) { res in
|
||||
#expect(res.status == .internalServerError)
|
||||
}
|
||||
try await transport.waitFor(1)
|
||||
try await Task.sleep(for: .milliseconds(100))
|
||||
#expect(transport.count == 1)
|
||||
let body = Self.content(transport.bodies[0])
|
||||
for secret in Self.secrets + ["alice"] {
|
||||
#expect(!body.contains(secret), "leaked \(secret)")
|
||||
}
|
||||
#expect(body.contains(#""route":"/e2e/devices/:device/keys/:handle""#))
|
||||
#expect(body.contains(#""status":"500""#))
|
||||
#expect(body.contains(#""method":"GET""#))
|
||||
#expect(body.contains(#""type":"Boom""#))
|
||||
// The handler's own line, scrubbed, is the message.
|
||||
#expect(body.contains("lookup failed for :handle on :path"))
|
||||
#expect(transport.urls[0] == "http://glitchtip-relay:8000/api/1/envelope/")
|
||||
#expect(transport.headers[0].contains { $0.0 == "X-Sentry-Auth" })
|
||||
}
|
||||
}
|
||||
|
||||
@Test("a 5xx with nothing logged is still reported; a 404 is not")
|
||||
func statusOnlyReporting() async throws {
|
||||
let transport = RecordingTransport()
|
||||
try await withReportingApp(transport) { app in
|
||||
try await app.testing().test(.GET, "/unavailable") { res in
|
||||
#expect(res.status == .serviceUnavailable)
|
||||
}
|
||||
try await app.testing().test(.GET, "/no/such/\(Self.accountID)") { res in
|
||||
#expect(res.status == .notFound)
|
||||
}
|
||||
try await transport.waitFor(1)
|
||||
try await Task.sleep(for: .milliseconds(100))
|
||||
#expect(transport.count == 1)
|
||||
#expect(transport.bodies[0].contains(#""status":"503""#))
|
||||
#expect(!Self.content(transport.bodies[0]).contains(Self.accountID))
|
||||
}
|
||||
}
|
||||
|
||||
// MARK: - Helpers
|
||||
|
||||
/// The event without its random id, timestamp and hash, which could
|
||||
/// contain any short digit run by chance.
|
||||
static func content(_ envelope: String) -> String {
|
||||
let lines = envelope.split(separator: "\n")
|
||||
guard lines.count == 3,
|
||||
var payload = try? JSONSerialization.jsonObject(with: Data(lines[2].utf8))
|
||||
as? [String: Any]
|
||||
else { return envelope }
|
||||
for key in ["event_id", "timestamp", "fingerprint"] { payload[key] = nil }
|
||||
let data = try! JSONSerialization.data(
|
||||
withJSONObject: payload, options: [.sortedKeys, .withoutEscapingSlashes])
|
||||
return String(decoding: data, as: UTF8.self)
|
||||
}
|
||||
|
||||
static func words(_ n: Int, offset: Int = 0) -> [String] {
|
||||
let letters = Array("abcdefghijklmnopqrstuvwxyz")
|
||||
return (offset..<(offset + n)).map { i in
|
||||
String([letters[i % 26], letters[(i / 26) % 26], letters[(i / 676) % 26]])
|
||||
}
|
||||
}
|
||||
|
||||
private struct Boom: Error, CustomStringConvertible {
|
||||
var description: String { "Boom" }
|
||||
}
|
||||
|
||||
/// The logger is swapped for one whose handler is the production wrapper,
|
||||
/// because the test process never bootstraps LoggingSystem with it.
|
||||
private struct UseReportingLogger: AsyncMiddleware {
|
||||
func respond(to request: Request, chainingTo next: any AsyncResponder) async throws
|
||||
-> Response
|
||||
{
|
||||
var logger = Logger(label: "codes.vapor.request") { label in
|
||||
ReportingLogHandler(
|
||||
label: label, inner: SwiftLogNoOpLogHandler(), reporter: { nil })
|
||||
}
|
||||
logger.logLevel = .error
|
||||
request.logger = logger
|
||||
return try await next.respond(to: request)
|
||||
}
|
||||
}
|
||||
|
||||
private func withReportingApp(
|
||||
_ transport: RecordingTransport, _ body: (Application) async throws -> Void
|
||||
) async throws {
|
||||
let app = try await Application.make(.testing)
|
||||
let reporter = ErrorReporter(dsn: Self.dsn, environment: "test", transport: transport)
|
||||
app.middleware = .init()
|
||||
app.middleware.use(UseReportingLogger())
|
||||
app.middleware.use(ErrorReportingMiddleware(reporter: reporter))
|
||||
app.middleware.use(ErrorMiddleware.default(environment: app.environment))
|
||||
app.middleware.use(ErrorTypeCaptureMiddleware())
|
||||
app.middleware.use(WireErrorMiddleware())
|
||||
app.get("e2e", "devices", ":device", "keys", ":handle") { req -> String in
|
||||
let line =
|
||||
"lookup failed for \(req.parameters.get("handle")!) on \(req.url.path) "
|
||||
+ "\(Self.everything) query=\(req.url.query ?? "")"
|
||||
req.logger.error("\(line)")
|
||||
throw Boom()
|
||||
}
|
||||
app.get("unavailable") { _ -> String in
|
||||
throw Abort(.serviceUnavailable)
|
||||
}
|
||||
do { try await body(app) } catch {
|
||||
try? await app.asyncShutdown()
|
||||
throw error
|
||||
}
|
||||
try? await app.asyncShutdown()
|
||||
}
|
||||
}
|
||||
|
||||
/// Records what would have been posted.
|
||||
final class RecordingTransport: ErrorTransport, @unchecked Sendable {
|
||||
private let lock = NSLock()
|
||||
private var _bodies: [String] = []
|
||||
private var _urls: [String] = []
|
||||
private var _headers: [[(String, String)]] = []
|
||||
|
||||
func post(url: String, headers: [(String, String)], body: Data) async {
|
||||
lock.withLock {
|
||||
_bodies.append(String(decoding: body, as: UTF8.self))
|
||||
_urls.append(url)
|
||||
_headers.append(headers)
|
||||
}
|
||||
}
|
||||
|
||||
var count: Int { lock.withLock { _bodies.count } }
|
||||
var bodies: [String] { lock.withLock { _bodies } }
|
||||
var urls: [String] { lock.withLock { _urls } }
|
||||
var headers: [[(String, String)]] { lock.withLock { _headers } }
|
||||
|
||||
func waitFor(_ n: Int, timeout: Duration = .seconds(3)) async throws {
|
||||
let deadline = ContinuousClock.now + timeout
|
||||
while count < n, ContinuousClock.now < deadline {
|
||||
try await Task.sleep(for: .milliseconds(10))
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
final class TestClock: @unchecked Sendable {
|
||||
private let lock = NSLock()
|
||||
private var t = Date(timeIntervalSince1970: 1_800_000_000)
|
||||
var now: Date { lock.withLock { t } }
|
||||
func advance(_ seconds: TimeInterval) { lock.withLock { t += seconds } }
|
||||
}
|
||||
@@ -87,6 +87,7 @@ store keeps its own copy of each.
|
||||
| `FN_HOST` | `127.0.0.1` | Not reachable from outside the host as shipped. Terminate TLS in front of it. |
|
||||
| `FN_PORT` | `8080` | |
|
||||
| `FN_LOG_LEVEL` | `error` | Never raise to `debug` on a machine with real accounts: it logs request URLs, and a protocol URL contains a device id. |
|
||||
| `FN_SENTRY_DSN` | unset | Error reporting to a Sentry-protocol collector you run (GlitchTip), as `http://<key>@<host>:<port>/<project>`. Unset sends nothing. Set, errors, criticals and 5xx responses each become one event: the message with account ids, device ids, addresses, tokens, emails and phone numbers removed, the error type, the route template (`/e2e/devices/:deviceID`, never the path asked for), method, status and the source line. No headers, bodies, query strings, addresses or logger metadata. Warnings stay on stdout; info and debug are never sent. At most 30 events a minute, one per fault per 60 seconds, 2 second timeout, no retries. The collector keeps what it receives for as long as it is configured to, so point it at one whose retention you have chosen. A value that is not a DSN stops the relay at start-up. |
|
||||
|
||||
**HTTPS is not optional in practice.** Clients hold key material, and serving
|
||||
them over plain HTTP hands it to anyone on the path. Forward the client address
|
||||
|
||||
Reference in New Issue
Block a user