diff --git a/Sources/App/Commands/Alerting.swift b/Sources/App/Commands/Alerting.swift index 301550684..84e375d5b 100644 --- a/Sources/App/Commands/Alerting.swift +++ b/Sources/App/Commands/Alerting.swift @@ -42,14 +42,15 @@ enum Alerting { } func run(using context: CommandContext, signature: Signature) async throws { - Current.setLogger(Logger(component: "alerting")) + @Dependency(\.logger) var logger + logger.set(to: Logger(component: "alerting")) - Current.logger().info("Running alerting...") + logger.info("Running alerting...") let timePeriod = signature.duration let limit = signature.limit ?? Alerting.defaultLimit - Current.logger().info("Validation time interval: \(timePeriod.hours)h, limit: \(limit)") + logger.info("Validation time interval: \(timePeriod.hours)h, limit: \(limit)") let builds = try await Alerting.fetchBuilds(on: context.application.db, timePeriod: timePeriod, limit: limit) try await Alerting.runBuildChecks(for: builds) @@ -94,12 +95,14 @@ extension Alerting { // to do // - [ ] doc gen is configured but it failed - Current.logger().info("Build records selected: \(builds.count)") + @Dependency(\.logger) var logger + + logger.info("Build records selected: \(builds.count)") if let oldest = builds.last { - Current.logger().info("Oldest selected: \(oldest.createdAt)") + logger.info("Oldest selected: \(oldest.createdAt)") } if let mostRecent = builds.first { - Current.logger().info("Most recent selected: \(mostRecent.createdAt)") + logger.info("Most recent selected: \(mostRecent.createdAt)") } builds.validateBuildsPresent().log(check: "CHECK_BUILDS_PRESENT") builds.validatePlatformsPresent().log(check: "CHECK_BUILDS_PLATFORMS_PRESENT") @@ -114,9 +117,11 @@ extension Alerting { } static func fetchBuilds(on database: Database, timePeriod: TimeAmount, limit: Int) async throws -> [Alerting.BuildInfo] { + @Dependency(\.logger) var logger + let start = Date.now defer { - Current.logger().debug("fetchBuilds elapsed: \(Date.now.timeIntervalSince(start).rounded(decimalPlaces: 2))s") + logger.debug("fetchBuilds elapsed: \(Date.now.timeIntervalSince(start).rounded(decimalPlaces: 2))s") } @Dependency(\.date.now) var now let cutoff = now.addingTimeInterval(-timePeriod.timeInterval) @@ -187,15 +192,16 @@ extension Alerting { case failed(reasons: [String]) func log(check: String) { + @Dependency(\.logger) var logger switch self { case .ok: - Current.logger().debug("\(check) passed") + logger.debug("\(check) passed") case .failed(let reasons): if reasons.count >= 5 { - Current.logger().critical("\(check) failures: \(reasons.count)") + logger.critical("\(check) failures: \(reasons.count)") } for reason in reasons { - Current.logger().critical("\(check) failed: \(reason)") + logger.critical("\(check) failed: \(reason)") } } } diff --git a/Sources/App/Commands/Analyze.swift b/Sources/App/Commands/Analyze.swift index 05dd61cfe..950ebd108 100644 --- a/Sources/App/Commands/Analyze.swift +++ b/Sources/App/Commands/Analyze.swift @@ -30,7 +30,8 @@ enum Analyze { func run(using context: CommandContext, signature: SPICommand.Signature) async throws { let client = context.application.client let db = context.application.db - Current.setLogger(Logger(component: "analyze")) + @Dependency(\.logger) var logger + logger.set(to: Logger(component: "analyze")) Analyze.resetMetrics() @@ -39,20 +40,20 @@ enum Analyze { database: db, mode: .init(signature: signature)) } catch { - Current.logger().error("\(error.localizedDescription)") + logger.error("\(error.localizedDescription)") } do { try Analyze.trimCheckouts() } catch { - Current.logger().error("\(error.localizedDescription)") + logger.error("\(error.localizedDescription)") } do { try await AppMetrics.push(client: client, jobName: "analyze") } catch { - Current.logger().warning("\(error.localizedDescription)") + logger.warning("\(error.localizedDescription)") } } } @@ -110,19 +111,21 @@ extension Analyze { let start = DispatchTime.now().uptimeNanoseconds defer { AppMetrics.analyzeDurationSeconds?.time(since: start) } + @Dependency(\.logger) var logger + switch mode { case .id(let id): - Current.logger().info("Analyzing (id: \(id)) ...") + logger.info("Analyzing (id: \(id)) ...") let pkg = try await Package.fetchCandidate(database, id: id) try await analyze(client: client, database: database, packages: [pkg]) case .limit(let limit): - Current.logger().info("Analyzing (limit: \(limit)) ...") + logger.info("Analyzing (limit: \(limit)) ...") let packages = try await Package.fetchCandidates(database, for: .analysis, limit: limit) try await analyze(client: client, database: database, packages: packages) case .url(let url): - Current.logger().info("Analyzing (url: \(url)) ...") + logger.info("Analyzing (url: \(url)) ...") let pkg = try await Package.fetchCandidate(database, url: url) try await analyze(client: client, database: database, packages: [pkg]) } @@ -140,10 +143,12 @@ extension Analyze { packages: [Joined]) async throws { AppMetrics.analyzeCandidatesCount?.set(packages.count) - // get or create directory @Dependency(\.fileManager) var fileManager + @Dependency(\.logger) var logger + + // get or create directory let checkoutDir = fileManager.checkoutsDirectory() - Current.logger().info("Checkout directory: \(checkoutDir)") + logger.info("Checkout directory: \(checkoutDir)") if !fileManager.fileExists(atPath: checkoutDir) { try await createCheckoutsDirectory(client: client, path: checkoutDir) } @@ -170,6 +175,8 @@ extension Analyze { package: Joined) async throws { try await refreshCheckout(package: package) + @Dependency(\.logger) var logger + // 2024-10-05 sas: We need to explicitly weave dependencies into the `transaction` closure, because escaping closures strip them. // https://github.com/pointfreeco/swift-dependencies/discussions/283#discussioncomment-10846172 // This might not be needed in Vapor 5 / FluentKit 2 @@ -183,7 +190,7 @@ extension Analyze { package: package) let netDeleteCount = versionDelta.toDelete.count - versionDelta.toAdd.count if netDeleteCount > 1 { - Current.logger().warning("Suspicious loss of \(netDeleteCount) versions for package \(package.model.id)") + logger.warning("Suspicious loss of \(netDeleteCount) versions for package \(package.model.id)") } try await applyVersionDelta(on: tx, delta: versionDelta) @@ -235,7 +242,8 @@ extension Analyze { static func createCheckoutsDirectory(client: Client, path: String) async throws { - Current.logger().info("Creating checkouts directory at path: \(path)") + @Dependency(\.logger) var logger + logger.info("Creating checkouts directory at path: \(path)") do { @Dependency(\.fileManager) var fileManager try fileManager.createDirectory(atPath: path, @@ -243,7 +251,7 @@ extension Analyze { attributes: nil) } catch { let error = AppError.genericError(nil, "Failed to create checkouts directory: \(error.localizedDescription)") - Current.logger().report(error: error) + logger.logger.report(error: error) } } @@ -254,7 +262,8 @@ extension Analyze { /// - url: url to clone from /// - Throws: Shell errors static func clone(cacheDir: String, url: String) async throws { - Current.logger().info("cloning \(url) to \(cacheDir)") + @Dependency(\.logger) var logger + logger.info("cloning \(url) to \(cacheDir)") @Dependency(\.fileManager) var fileManager @Dependency(\.shell) var shell try await shell.run(command: .gitClone(url: URL(string: url)!, to: cacheDir), @@ -270,13 +279,14 @@ extension Analyze { /// - Throws: Shell errors static func fetch(cacheDir: String, branch: String, url: String) async throws { @Dependency(\.fileManager) var fileManager + @Dependency(\.logger) var logger @Dependency(\.shell) var shell - Current.logger().info("pulling \(url) in \(cacheDir)") + logger.info("pulling \(url) in \(cacheDir)") // clean up stray lock files that might have remained from aborted commands for fileName in ["HEAD.lock", "index.lock"] { let filePath = cacheDir + "/.git/\(fileName)" if fileManager.fileExists(atPath: filePath) { - Current.logger().info("Removing stale \(fileName) at path: \(filePath)") + logger.info("Removing stale \(fileName) at path: \(filePath)") try await shell.run(command: .removeFile(from: filePath), at: .cwd) } } @@ -294,6 +304,7 @@ extension Analyze { /// - package: `Package` to refresh static func refreshCheckout(package: Joined) async throws { @Dependency(\.fileManager) var fileManager + @Dependency(\.logger) var logger @Dependency(\.shell) var shell guard let cacheDir = fileManager.cacheDirectoryPath(for: package.model) else { @@ -313,7 +324,7 @@ extension Analyze { branch: package.repository?.defaultBranch ?? "master", url: package.model.url) } catch { - Current.logger().info("fetch failed: \(error.localizedDescription)") + logger.info("fetch failed: \(error.localizedDescription)") try await shell.run(command: .removeFile(from: cacheDir, arguments: ["-r", "-f"]), at: .cwd) try await clone(cacheDir: cacheDir, url: package.model.url) } @@ -357,6 +368,8 @@ extension Analyze { static func diffVersions(client: Client, transaction: Database, package: Joined) async throws -> VersionDelta { + @Dependency(\.logger) var logger + guard let pkgId = package.model.id else { throw AppError.genericError(nil, "PANIC: package id nil for package \(package.model.url)") } @@ -374,7 +387,7 @@ extension Analyze { let newDiff = Version.diff(local: existing, incoming: throttled) let delta = origDiff.toAdd.count - newDiff.toAdd.count if delta > 0 { - Current.logger().info("throttled \(delta) incoming revisions") + logger.info("throttled \(delta) incoming revisions") AppMetrics.buildThrottleCount?.inc(delta) } return newDiff @@ -506,12 +519,13 @@ extension Analyze { /// have processed the new version. /// - Parameter versionDelta: The version change static func carryOverDefaultBranchData(versionDelta: VersionDelta) { + @Dependency(\.logger) var logger guard versionDelta.toDelete.filter(\.isBranch).count <= 1 else { - Current.logger().warning("versionDelta.toDelete has more than one branch version") + logger.warning("versionDelta.toDelete has more than one branch version") return } guard versionDelta.toAdd.filter(\.isBranch).count <= 1 else { - Current.logger().warning("versionDelta.toAdd has more than one branch version") + logger.warning("versionDelta.toAdd has more than one branch version") return } guard let oldDefaultBranch = versionDelta.toDelete.first(where: \.isBranch), @@ -745,7 +759,8 @@ extension Analyze { package: package, versions: versions) } catch { - Current.logger().warning("Social.postToFirehose failed: \(error.localizedDescription)") + @Dependency(\.logger) var logger + logger.warning("Social.postToFirehose failed: \(error.localizedDescription)") } } diff --git a/Sources/App/Commands/Common.swift b/Sources/App/Commands/Common.swift index 41a2c81ea..e865f57a1 100644 --- a/Sources/App/Commands/Common.swift +++ b/Sources/App/Commands/Common.swift @@ -12,6 +12,7 @@ // See the License for the specific language governing permissions and // limitations under the License. +import Dependencies import Fluent import PostgresKit import Vapor @@ -39,33 +40,35 @@ extension Analyze { static func updatePackages(client: Client, database: Database, results: [Result, Error>]) async throws { + @Dependency(\.logger) var logger do { let total = results.count let errors = results.filter(\.isError).count let errorRate = total > 0 ? 100.0 * Double(errors) / Double(total) : 0.0 switch errorRate { case 0: - Current.logger().info("Updating \(total) packages for stage 'analysis'") + logger.info("Updating \(total) packages for stage 'analysis'") case 0..<20: - Current.logger().info("Updating \(total) packages for stage 'analysis' (errors: \(errors))") + logger.info("Updating \(total) packages for stage 'analysis' (errors: \(errors))") default: - Current.logger().critical("updatePackages: unusually high error rate: \(errors)/\(total) = \(errorRate)%") + logger.critical("updatePackages: unusually high error rate: \(errors)/\(total) = \(errorRate)%") } } for result in results { do { try await updatePackage(client: client, database: database, result: result) } catch { - Current.logger().critical("updatePackage failed: \(error)") + logger.critical("updatePackage failed: \(error)") } } - Current.logger().debug("updateStatus ops: \(results.count)") + logger.debug("updateStatus ops: \(results.count)") } static func updatePackage(client: Client, database: Database, result: Result, Error>) async throws { + @Dependency(\.logger) var logger switch result { case .success(let res): try await res.package.update(on: database, status: .ok, stage: .analysis) @@ -76,16 +79,16 @@ extension Analyze { // Escalate database errors to critical let error = error as! PSQLError let msg = error.serverInfo?[.message] ?? String(reflecting: error) - Current.logger().critical("\(msg)") + logger.critical("\(msg)") try await recordError(database: database, error: error) case let .failure(error) where error is DatabaseError: // Escalate database errors to critical - Current.logger().critical("\(String(reflecting: error))") + logger.critical("\(String(reflecting: error))") try await recordError(database: database, error: error) case let .failure(error): - Current.logger().report(error: error) + logger.report(error: error) try await recordError(database: database, error: error) } } @@ -128,13 +131,14 @@ extension Ingestion { database: Database, result: Result, Ingestion.Error>, stage: Package.ProcessingStage) async throws { + @Dependency(\.logger) var logger switch result { case .success(let res): // for newly ingested package leave status == .new in order to fast-track analysis let updatedStatus: Package.Status = res.package.status == .new ? .new : .ok try await res.package.update(on: database, status: updatedStatus, stage: stage) case .failure(let failure): - Current.logger().log(level: failure.level, "\(failure)") + logger.log(level: failure.level, "\(failure)") try await Package.update(for: failure.packageId, on: database, status: failure.status, stage: stage) } } diff --git a/Sources/App/Commands/Ingestion.swift b/Sources/App/Commands/Ingestion.swift index d9ad102ce..47e8996a4 100644 --- a/Sources/App/Commands/Ingestion.swift +++ b/Sources/App/Commands/Ingestion.swift @@ -84,21 +84,22 @@ enum Ingestion { func run(using context: CommandContext, signature: SPICommand.Signature) async { let client = context.application.client let db = context.application.db - Current.setLogger(Logger(component: "ingest")) + @Dependency(\.logger) var logger + logger.set(to: Logger(component: "ingest")) Self.resetMetrics() do { try await ingest(client: client, database: db, mode: .init(signature: signature)) } catch { - Current.logger().error("\(error.localizedDescription)") + logger.error("\(error.localizedDescription)") } do { try await AppMetrics.push(client: client, jobName: "ingest") } catch { - Current.logger().warning("\(error.localizedDescription)") + logger.warning("\(error.localizedDescription)") } } @@ -121,20 +122,22 @@ enum Ingestion { let start = DispatchTime.now().uptimeNanoseconds defer { AppMetrics.ingestDurationSeconds?.time(since: start) } + @Dependency(\.logger) var logger + switch mode { case .id(let id): - Current.logger().info("Ingesting (id: \(id)) ...") + logger.info("Ingesting (id: \(id)) ...") let pkg = try await Package.fetchCandidate(database, id: id) await ingest(client: client, database: database, packages: [pkg]) case .limit(let limit): - Current.logger().info("Ingesting (limit: \(limit)) ...") + logger.info("Ingesting (limit: \(limit)) ...") let packages = try await Package.fetchCandidates(database, for: .ingestion, limit: limit) - Current.logger().info("Candidate count: \(packages.count)") + logger.info("Candidate count: \(packages.count)") await ingest(client: client, database: database, packages: packages) case .url(let url): - Current.logger().info("Ingesting (url: \(url)) ...") + logger.info("Ingesting (url: \(url)) ...") let pkg = try await Package.fetchCandidate(database, url: url) await ingest(client: client, database: database, packages: [pkg]) } @@ -150,7 +153,8 @@ enum Ingestion { static func ingest(client: Client, database: Database, packages: [Joined]) async { - Current.logger().debug("Ingesting \(packages.compactMap {$0.model.id})") + @Dependency(\.logger) var logger + logger.debug("Ingesting \(packages.compactMap {$0.model.id})") AppMetrics.ingestCandidatesCount?.set(packages.count) await withTaskGroup(of: Void.self) { group in @@ -164,9 +168,10 @@ enum Ingestion { static func ingest(client: Client, database: Database, package: Joined) async { + @Dependency(\.logger) var logger let result = await Result { () async throws(Ingestion.Error) -> Joined in @Dependency(\.environment) var environment - Current.logger().info("Ingesting \(package.package.url)") + logger.info("Ingesting \(package.package.url)") // Even though we have a `Joined` as a parameter, we must not rely // on `repository` for owner/name as it will be nil when a package is first ingested. @@ -193,7 +198,7 @@ enum Ingestion { s3Readme = try await storeS3Readme(repository: repo, metadata: metadata, readme: readme) } catch { // We don't want to fail ingestion in case storing the readme fails - warn and continue. - Current.logger().warning("storeS3Readme failed: \(error)") + logger.warning("storeS3Readme failed: \(error)") s3Readme = .error("\(error)") } @@ -217,7 +222,7 @@ enum Ingestion { do { try await updatePackage(client: client, database: database, result: result, stage: .ingestion) } catch { - Current.logger().report(error: error) + logger.report(error: error) } } diff --git a/Sources/App/Commands/ReAnalyzeVersions.swift b/Sources/App/Commands/ReAnalyzeVersions.swift index aab0b5d76..5741908cf 100644 --- a/Sources/App/Commands/ReAnalyzeVersions.swift +++ b/Sources/App/Commands/ReAnalyzeVersions.swift @@ -47,11 +47,12 @@ enum ReAnalyzeVersions { let client = context.application.client let db = context.application.db - Current.setLogger(Logger(component: "re-analyze-versions")) + @Dependency(\.logger) var logger + logger.set(to: Logger(component: "re-analyze-versions")) @Dependency(\.date.now) var now if let id = signature.packageId { - Current.logger().info("Re-analyzing versions (id: \(id)) ...") + logger.info("Re-analyzing versions (id: \(id)) ...") do { try await reAnalyzeVersions( client: client, @@ -61,20 +62,20 @@ enum ReAnalyzeVersions { packageId: id ) } catch { - Current.logger().error("\(error.localizedDescription)") + logger.error("\(error.localizedDescription)") } } else { guard let cutoffDate = signature.before else { - Current.logger().info("No cut-off date set, skipping re-analysis") + logger.info("No cut-off date set, skipping re-analysis") return } - Current.logger().info("Re-analyzing versions (limit: \(limit)) ...") + logger.info("Re-analyzing versions (limit: \(limit)) ...") var processed = 0 while processed < limit { let currentBatchSize = min(signature.batchSize ?? defaultBatchSize, limit - processed) - Current.logger().info("Re-analyzing versions (batch: \(processed)..<\(processed + currentBatchSize)) ...") + logger.info("Re-analyzing versions (batch: \(processed)..<\(processed + currentBatchSize)) ...") do { try await reAnalyzeVersions( client: client, @@ -85,17 +86,17 @@ enum ReAnalyzeVersions { ) processed += currentBatchSize } catch { - Current.logger().error("\(error.localizedDescription)") + logger.error("\(error.localizedDescription)") } } } do { try await AppMetrics.push(client: client, jobName: "re-analyze-versions") } catch { - Current.logger().warning("\(error.localizedDescription)") + logger.warning("\(error.localizedDescription)") } - Current.logger().info("Done.") + logger.info("Done.") } } @@ -173,8 +174,10 @@ enum ReAnalyzeVersions { // case by design, as `analyze` will only add or remove versions, ignoring // existing ones. + @Dependency(\.logger) var logger + for pkg in packages { - Current.logger().info("Re-analyzing package \(pkg.model.url) ...") + logger.info("Re-analyzing package \(pkg.model.url) ...") // 2024-10-05 sas: We need to explicitly weave dependencies into the `transaction` closure, because escaping closures strip them. // https://github.com/pointfreeco/swift-dependencies/discussions/283#discussioncomment-10846172 @@ -193,8 +196,8 @@ enum ReAnalyzeVersions { transaction: tx, package: pkg, before: cutoffDate) - Current.logger().info("Updating \(versions.count) versions (id: \(pkg.model.id)) ...") - + logger.info("Updating \(versions.count) versions (id: \(pkg.model.id)) ...") + try await setUpdatedAt(on: tx, versions: versions) Analyze.mergeReleaseInfo(package: pkg, into: versions) @@ -204,7 +207,7 @@ enum ReAnalyzeVersions { do { pkgInfo = try await Analyze.getPackageInfo(package: pkg, version: version) } catch { - Current.logger().report(error: error) + logger.report(error: error) continue } diff --git a/Sources/App/Commands/Reconcile.swift b/Sources/App/Commands/Reconcile.swift index 80b2c8690..90f31195b 100644 --- a/Sources/App/Commands/Reconcile.swift +++ b/Sources/App/Commands/Reconcile.swift @@ -23,24 +23,25 @@ struct ReconcileCommand: AsyncCommand { var help: String { "Reconcile package list with server" } func run(using context: CommandContext, signature: Signature) async throws { - Current.setLogger(Logger(component: "reconcile")) + @Dependency(\.logger) var logger + logger.set(to: Logger(component: "reconcile")) - Current.logger().info("Reconciling...") + logger.info("Reconciling...") do { try await reconcile(client: context.application.client, database: context.application.db) } catch { - Current.logger().error("\(error)") + logger.error("\(error)") } - Current.logger().info("done.") + logger.info("done.") do { try await AppMetrics.push(client: context.application.client, jobName: "reconcile") } catch { - Current.logger().warning("\(error)") + logger.warning("\(error)") } } } @@ -50,16 +51,18 @@ func reconcile(client: Client, database: Database) async throws { let start = DispatchTime.now().uptimeNanoseconds defer { AppMetrics.reconcileDurationSeconds?.time(since: start) } + @Dependency(\.logger) var logger + // reconcile main package list - Current.logger().info("Reconciling main list...") + logger.info("Reconciling main list...") let fullPackageList = try await reconcileMainPackageList(client: client, database: database) do { // reconcile custom package collections - Current.logger().info("Reconciling custom collections...") + logger.info("Reconciling custom collections...") @Dependency(\.packageListRepository) var packageListRepository let collections = try await packageListRepository.fetchCustomCollections(client: client) for collection in collections { - Current.logger().info("Reconciling '\(collection.name)' collection...") + logger.info("Reconciling '\(collection.name)' collection...") try await reconcileCustomCollection(client: client, database: database, fullPackageList: fullPackageList, collection) } } diff --git a/Sources/App/Commands/TriggerBuilds.swift b/Sources/App/Commands/TriggerBuilds.swift index ff361df2c..2fc9ce4aa 100644 --- a/Sources/App/Commands/TriggerBuilds.swift +++ b/Sources/App/Commands/TriggerBuilds.swift @@ -55,7 +55,8 @@ struct TriggerBuildsCommand: AsyncCommand { } func run(using context: CommandContext, signature: Signature) async throws { - Current.setLogger(Logger(component: "trigger-builds")) + @Dependency(\.logger) var logger + logger.set(to: Logger(component: "trigger-builds")) Self.resetMetrics() @@ -87,14 +88,14 @@ struct TriggerBuildsCommand: AsyncCommand { do { try await triggerBuilds(on: context.application.db, mode: mode) } catch { - Current.logger().critical("\(error)") + logger.critical("\(error)") } do { try await AppMetrics.push(client: context.application.client, jobName: "trigger-builds") } catch { - Current.logger().warning("\(error)") + logger.warning("\(error)") } } @@ -122,11 +123,13 @@ extension TriggerBuildsCommand { /// or a fetch limit for candidate selection. func triggerBuilds(on database: Database, mode: TriggerBuildsCommand.Mode) async throws { @Dependency(\.environment) var environment + @Dependency(\.logger) var logger + let start = DispatchTime.now().uptimeNanoseconds switch mode { case .limit(let limit): - Current.logger().info("Triggering builds (limit: \(limit)) ...") + logger.info("Triggering builds (limit: \(limit)) ...") let withLatestSwiftVersion = environment.buildTriggerCandidatesWithLatestSwiftVersion let candidates = try await fetchBuildCandidates(database, @@ -138,18 +141,18 @@ func triggerBuilds(on database: Database, mode: TriggerBuildsCommand.Mode) async AppMetrics.buildTriggerDurationSeconds?.time(since: start) case let .packageId(id, force): - Current.logger().info("Triggering builds (packageID: \(id)) ...") + logger.info("Triggering builds (packageID: \(id)) ...") try await triggerBuilds(on: database, packages: [id], force: force) AppMetrics.buildTriggerDurationSeconds?.time(since: start) case let .triggerInfo(versionId, buildPair, isDocBuild): - Current.logger().info("Triggering builds (versionID: \(versionId), \(buildPair)) ...") + logger.info("Triggering builds (versionID: \(versionId), \(buildPair)) ...") guard let trigger = BuildTriggerInfo(versionId: versionId, buildPairs: [buildPair], docPairs: isDocBuild ? [buildPair] : []) else { - Current.logger().error("Failed to create trigger.") + logger.error("Failed to create trigger.") return } try await triggerBuildsUnchecked(on: database, triggers: [trigger]) @@ -170,9 +173,10 @@ func triggerBuilds(on database: Database, force: Bool = false) async throws { @Dependency(\.environment) var environment @Dependency(\.buildSystem) var buildSystem + @Dependency(\.logger) var logger guard environment.allowBuildTriggers() else { - Current.logger().info("Build trigger override switch OFF - no builds are being triggered") + logger.info("Build trigger override switch OFF - no builds are being triggered") return } @@ -203,24 +207,24 @@ func triggerBuilds(on database: Database, for pkgId in packages { let allowListed = environment.buildTriggerAllowList().contains(pkgId) guard allowListed || environment.buildTriggerDownscalingAccepted else { - Current.logger().info("Build trigger downscaling in effect - skipping builds") + logger.info("Build trigger downscaling in effect - skipping builds") continue } - group.addTask { + group.addTask { [logger] in // check if we have capacity to schedule more builds before querying for builds var newJobCount = await newJobs.value guard pendingJobs + newJobCount < gitlabPipelineLimit() else { - Current.logger().info("too many pending pipelines (\(pendingJobs + newJobCount))") + logger.info("too many pending pipelines (\(pendingJobs + newJobCount))") return } - Current.logger().info("Finding missing builds for package id: \(pkgId)") + logger.info("Finding missing builds for package id: \(pkgId)") let triggers = try await findMissingBuilds(database, packageId: pkgId) newJobCount = await newJobs.value guard pendingJobs + newJobCount < gitlabPipelineLimit() else { - Current.logger().info("too many pending pipelines (\(pendingJobs + newJobCount))") + logger.info("too many pending pipelines (\(pendingJobs + newJobCount))") return } @@ -244,12 +248,13 @@ func triggerBuilds(on database: Database, /// - client: `Client` used for http request /// - triggers: trigger information for builds to trigger func triggerBuildsUnchecked(on database: Database, triggers: [BuildTriggerInfo]) async throws { + @Dependency(\.logger) var logger await withThrowingTaskGroup(of: Void.self) { group in for trigger in triggers { if let packageName = trigger.packageName, let reference = trigger.reference { - Current.logger().info("Triggering \(pluralizedCount: trigger.buildPairs.count, singular: "build") for package name: \(packageName), ref: \(reference)") + logger.info("Triggering \(pluralizedCount: trigger.buildPairs.count, singular: "build") for package name: \(packageName), ref: \(reference)") } else { - Current.logger().info("Triggering \(pluralizedCount: trigger.buildPairs.count, singular: "build") for version ID: \(trigger.versionId)") + logger.info("Triggering \(pluralizedCount: trigger.buildPairs.count, singular: "build") for version ID: \(trigger.versionId)") } for pair in trigger.buildPairs { diff --git a/Sources/App/Core/AppEnvironment.swift b/Sources/App/Core/AppEnvironment.swift deleted file mode 100644 index 0ab71acf8..000000000 --- a/Sources/App/Core/AppEnvironment.swift +++ /dev/null @@ -1,45 +0,0 @@ -// Copyright Dave Verwer, Sven A. Schmidt, and other contributors. -// -// Licensed under the Apache License, Version 2.0 (the "License"); -// you may not use this file except in compliance with the License. -// You may obtain a copy of the License at -// -// http://www.apache.org/licenses/LICENSE-2.0 -// -// Unless required by applicable law or agreed to in writing, software -// distributed under the License is distributed on an "AS IS" BASIS, -// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. -// See the License for the specific language governing permissions and -// limitations under the License. - -import AsyncHTTPClient -import S3Store -import SPIManifest -import ShellOut -import Vapor -#if canImport(FoundationNetworking) -import FoundationNetworking -#endif - - -struct AppEnvironment: Sendable { - var logger: @Sendable () -> Logger - var setLogger: @Sendable (Logger) -> Void -} - - -extension AppEnvironment { - nonisolated(unsafe) static var logger: Logger! - - static let live = AppEnvironment( - logger: { logger }, - setLogger: { logger in Self.logger = logger } - ) -} - - -#if DEBUG -nonisolated(unsafe) var Current: AppEnvironment = .live -#else -let Current: AppEnvironment = .live -#endif diff --git a/Sources/App/Core/AppMetrics.swift b/Sources/App/Core/AppMetrics.swift index db3cb1ada..c2c4ddb8a 100644 --- a/Sources/App/Core/AppMetrics.swift +++ b/Sources/App/Core/AppMetrics.swift @@ -172,6 +172,8 @@ extension AppMetrics { /// - Parameter client: client for POST request static func push(client: Client, jobName: String) async throws { @Dependency(\.environment) var environment + @Dependency(\.logger) var logger + guard let pushGatewayUrl = environment.metricsPushGatewayUrl() else { throw AppError.envVariableNotSet("METRICS_PUSHGATEWAY_URL") } @@ -185,7 +187,7 @@ extension AppMetrics { try req.content.encode(metrics + "\n") } } catch { - Current.logger().warning("AppMetrics.push failed with error: \(error)") + logger.warning("AppMetrics.push failed with error: \(error)") // ignore error - we don't want metrics issues to cause upstream failures } } diff --git a/Sources/App/Core/Authentication/User.swift b/Sources/App/Core/Authentication/User.swift index bf25235c7..75a05b88a 100644 --- a/Sources/App/Core/Authentication/User.swift +++ b/Sources/App/Core/Authentication/User.swift @@ -36,6 +36,7 @@ extension User { var tier: Tier @Dependency(\.environment) var environment + @Dependency(\.logger) var logger func authenticate(bearer: BearerAuthorization, for request: Request) async throws { guard let signingKey = environment.apiSigningKey() else { throw AppError.envVariableNotSet("API_SIGNING_KEY") } @@ -45,7 +46,7 @@ extension User { guard key.isAuthorized(for: tier) else { throw Abort(.unauthorized) } request.auth.login(User.api(for: bearer.token)) } catch let error as JWTError { - Current.logger().warning("\(error)") + logger.warning("\(error)") throw Abort(.unauthorized) } } diff --git a/Sources/App/Core/Dependencies/LoggerClient.swift b/Sources/App/Core/Dependencies/LoggerClient.swift new file mode 100644 index 000000000..b5cd45b59 --- /dev/null +++ b/Sources/App/Core/Dependencies/LoggerClient.swift @@ -0,0 +1,68 @@ +// Copyright Dave Verwer, Sven A. Schmidt, and other contributors. +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +import Dependencies +import DependenciesMacros +import Logging +import Synchronization + + +@DependencyClient +struct LoggerClient { + var log: @Sendable (_ level: Logging.Logger.Level, Logging.Logger.Message) -> Void + var set: @Sendable (_ to: Logging.Logger) -> Void +} + + +extension LoggerClient { + func critical(_ message: Logging.Logger.Message) { log(.critical, message) } + func debug(_ message: Logging.Logger.Message) { log(.debug, message) } + func error(_ message: Logging.Logger.Message) { log(.error, message) } + func info(_ message: Logging.Logger.Message) { log(.info, message) } + func warning(_ message: Logging.Logger.Message) { log(.warning, message) } + func trace(_ message: Logging.Logger.Message) { log(.trace, message) } + func report(error: Error, file: String = #fileID, function: String = #function, line: UInt = #line) { + logger.report(error: error, file: file, function: function, line: line) + } + var logger: Logging.Logger { Self._logger.withLock { $0 } } +} + + +extension LoggerClient: DependencyKey { + static var liveValue: Self { + .init( + log: { level, message in + _logger.withLock { $0.log(level: level, message) } + }, + set: { logger in + _logger.withLock { $0 = logger } + } + ) + } + + private static let _logger = Mutex(Logging.Logger(component: "default")) +} + + +extension LoggerClient: TestDependencyKey { + static var testValue: Self { liveValue } +} + + +extension DependencyValues { + var logger: LoggerClient { + get { self[LoggerClient.self] } + set { self[LoggerClient.self] = newValue } + } +} diff --git a/Sources/App/Core/Dependencies/RedisClient.swift b/Sources/App/Core/Dependencies/RedisClient.swift index 190a27d5b..d94d557db 100644 --- a/Sources/App/Core/Dependencies/RedisClient.swift +++ b/Sources/App/Core/Dependencies/RedisClient.swift @@ -93,7 +93,8 @@ private actor Redis { return try await Redis() } catch { attemptsLeft -= 1 - Current.logger().warning("Redis connection failed, \(attemptsLeft) attempts left. Error: \(error)") + @Dependency(\.logger) var logger + logger.warning("Redis connection failed, \(attemptsLeft) attempts left. Error: \(error)") try? await Task.sleep(for: .milliseconds(500)) } } diff --git a/Sources/App/Core/Dependencies/ShellClient.swift b/Sources/App/Core/Dependencies/ShellClient.swift index 16c735055..4efa5a510 100644 --- a/Sources/App/Core/Dependencies/ShellClient.swift +++ b/Sources/App/Core/Dependencies/ShellClient.swift @@ -40,10 +40,11 @@ extension ShellClient: DependencyKey { static var liveValue: Self { .init( run: { command, path in + @Dependency(\.logger) var logger do { - let res = try await ShellOut.shellOut(to: command, at: path, logger: Current.logger()) + let res = try await ShellOut.shellOut(to: command, at: path, logger: logger.logger) if !res.stderr.isEmpty { - Current.logger().warning("stderr: \(res.stderr)") + logger.warning("stderr: \(res.stderr)") } return res.stdout } catch { diff --git a/Sources/App/Core/ErrorMiddleware.swift b/Sources/App/Core/ErrorMiddleware.swift index 860ca8e24..f78dc68c1 100644 --- a/Sources/App/Core/ErrorMiddleware.swift +++ b/Sources/App/Core/ErrorMiddleware.swift @@ -12,6 +12,7 @@ // See the License for the specific language governing permissions and // limitations under the License. +import Dependencies import Plot import Vapor @@ -28,10 +29,12 @@ final class ErrorMiddleware: AsyncMiddleware { let statusCode = error.status.code let isCritical = (statusCode >= 500) + @Dependency(\.logger) var logger + if isCritical { - Current.logger().critical("\(error): \(req.url)") + logger.critical("\(error): \(req.url)") } else { - Current.logger().error("\(error): \(req.url)") + logger.error("\(error): \(req.url)") } return ErrorPage.View(path: req.url.path, error: error) diff --git a/Sources/App/Core/Extensions/S3Readme+ext.swift b/Sources/App/Core/Extensions/S3Readme+ext.swift index 7d222d3cb..0b33ca57f 100644 --- a/Sources/App/Core/Extensions/S3Readme+ext.swift +++ b/Sources/App/Core/Extensions/S3Readme+ext.swift @@ -42,12 +42,14 @@ extension S3Readme { static func storeReadme(owner: String, repository: String, readme: String) async throws(S3Readme.Error) -> String { @Dependency(\.environment) var environment + @Dependency(\.logger) var logger + guard let accessKeyId = environment.awsAccessKeyId() else { throw .envVariableNotSet("AWS_ACCESS_KEY_ID") } guard let secretAccessKey = environment.awsSecretAccessKey() else { throw .envVariableNotSet("AWS_SECRET_ACCESS_KEY")} let store = S3Store(credentials: .init(keyId: accessKeyId, secret: secretAccessKey)) let key = try S3Store.Key.readme(owner: owner, repository: repository) - Current.logger().debug("Copying readme to \(key.s3Uri) ...") + logger.debug("Copying readme to \(key.s3Uri) ...") do { try await store.save(payload: readme, to: key) } catch { @@ -60,12 +62,14 @@ extension S3Readme { static func storeReadmeImages(imagesToCache: [Github.Readme.ImageToCache]) async throws(S3Readme.Error) { @Dependency(\.environment) var environment @Dependency(\.httpClient) var httpClient + @Dependency(\.logger) var logger + guard let accessKeyId = environment.awsAccessKeyId() else { throw .envVariableNotSet("AWS_ACCESS_KEY_ID") } guard let secretAccessKey = environment.awsSecretAccessKey() else { throw .envVariableNotSet("AWS_SECRET_ACCESS_KEY")} let store = S3Store(credentials: .init(keyId: accessKeyId, secret: secretAccessKey)) for imageToCache in imagesToCache { - Current.logger().debug("Copying readme image to \(imageToCache.s3Key.s3Uri) ...") + logger.debug("Copying readme image to \(imageToCache.s3Key.s3Uri) ...") do { let response = try await httpClient.get(url: imageToCache.originalUrl) if var body = response.body, let imageData = body.readData(length: body.readableBytes) { diff --git a/Sources/App/Core/Git.swift b/Sources/App/Core/Git.swift index 06ba30329..53eb69837 100644 --- a/Sources/App/Core/Git.swift +++ b/Sources/App/Core/Git.swift @@ -82,6 +82,7 @@ enum Git { static func revisionInfo(_ reference: Reference, at path: String) async throws -> RevisionInfo { @Dependency(\.shell) var shell + @Dependency(\.logger) var logger let separator = "-" let res = String( try await shell.run(command: .gitRevisionInfo(reference: reference, separator: separator), @@ -90,7 +91,7 @@ enum Git { ) let parts = res.components(separatedBy: separator) guard parts.count == 2 else { - Current.logger().warning(#"Git.invalidRevisionInfo: \#(res) for '\#(ShellOutCommand.gitRevisionInfo(reference: reference, separator: separator))' at: \#(path)"#) + logger.warning(#"Git.invalidRevisionInfo: \#(res) for '\#(ShellOutCommand.gitRevisionInfo(reference: reference, separator: separator))' at: \#(path)"#) throw Error.invalidRevisionInfo(res) } let hash = parts[0] diff --git a/Sources/App/Core/Github.swift b/Sources/App/Core/Github.swift index 1cde1459d..b4bc2288c 100644 --- a/Sources/App/Core/Github.swift +++ b/Sources/App/Core/Github.swift @@ -89,6 +89,7 @@ extension Github { static func fetch(url: String, headers: [(String, String)] = []) async throws -> (content: String, etag: String?) { @Dependency(\.github) var github @Dependency(\.httpClient) var httpClient + @Dependency(\.logger) var logger guard let token = github.token() else { throw Error.missingToken @@ -98,17 +99,17 @@ extension Github { let response = try await httpClient.get(url: url, headers: defaultHeaders(with: token).adding(contentsOf: headers)) guard !isRateLimited(response) else { - Current.logger().critical("rate limited while fetching \(url)") + logger.critical("rate limited while fetching \(url)") throw Error.requestFailed(.tooManyRequests) } guard response.status == .ok else { - Current.logger().warning("Github.fetch of '\(url)' failed with status \(response.status)") + logger.warning("Github.fetch of '\(url)' failed with status \(response.status)") throw Error.requestFailed(response.status) } guard let body = response.body else { - Current.logger().warning("Github.fetch has no body") + logger.warning("Github.fetch has no body") throw Error.noBody } @@ -117,6 +118,7 @@ extension Github { static func fetchResource(_ type: T.Type, url: String) async throws -> T { @Dependency(\.github) var github + @Dependency(\.logger) var logger guard let token = github.token() else { throw Error.missingToken @@ -127,7 +129,7 @@ extension Github { let response = try await httpClient.get(url: url, headers: defaultHeaders(with: token)) guard !isRateLimited(response) else { - Current.logger().critical("rate limited while fetching resource \(url)") + logger.critical("rate limited while fetching resource \(url)") throw Error.requestFailed(.tooManyRequests) } @@ -181,13 +183,13 @@ extension Github { static func fetchResource(_ type: T.Type, query: GraphQLQuery) async throws(Github.Error) -> T { @Dependency(\.github) var github + @Dependency(\.httpClient) var httpClient + @Dependency(\.logger) var logger guard let token = github.token() else { throw Error.missingToken } - @Dependency(\.httpClient) var httpClient - let body = try run { try JSONEncoder().encode(query) } rethrowing: { @@ -201,12 +203,12 @@ extension Github { } guard !isRateLimited(response) else { - Current.logger().critical("rate limited while fetching resource \(T.self)") + logger.critical("rate limited while fetching resource \(T.self)") throw Error.requestFailed(.tooManyRequests) } guard response.status == .ok else { - Current.logger().warning("fetchResource<\(T.self)> request failed with status \(response.status)") + logger.warning("fetchResource<\(T.self)> request failed with status \(response.status)") throw Error.requestFailed(response.status) } diff --git a/Sources/App/Core/Gitlab.swift b/Sources/App/Core/Gitlab.swift index baca2a87a..85b643af9 100644 --- a/Sources/App/Core/Gitlab.swift +++ b/Sources/App/Core/Gitlab.swift @@ -79,6 +79,7 @@ extension Gitlab.Builder { versionID: Version.Id) async throws -> Build.TriggerResponse { @Dependency(\.environment) var environment @Dependency(\.httpClient) var httpClient + @Dependency(\.logger) var logger guard let pipelineToken = environment.gitlabPipelineToken(), let builderToken = environment.builderToken() @@ -116,11 +117,11 @@ extension Gitlab.Builder { guard let body = response.body else { throw Gitlab.Error.noBody } let webUrl = try JSONDecoder().decode(Response.self, from: body).webUrl let res = Build.TriggerResponse(status: response.status, webUrl: webUrl) - Current.logger().info("Triggered build: \(res.webUrl)") + logger.info("Triggered build: \(res.webUrl)") return res } catch { let body = response.body?.asString() ?? "nil" - Current.logger().error("Trigger failed: \(cloneURL) @ \(reference), \(platform) / \(swiftVersion), \(versionID), status: \(response.status), body: \(body)") + logger.error("Trigger failed: \(cloneURL) @ \(reference), \(platform) / \(swiftVersion), \(versionID), status: \(response.status), body: \(body)") return .init(status: response.status, webUrl: nil) } } diff --git a/Sources/App/Views/Plot+Extensions.swift b/Sources/App/Views/Plot+Extensions.swift index a877d0fbc..f4260b34d 100644 --- a/Sources/App/Views/Plot+Extensions.swift +++ b/Sources/App/Views/Plot+Extensions.swift @@ -41,7 +41,8 @@ extension Node where Context: HTML.BodyContext { .raw(rawScript) ) } catch { - AppEnvironment.logger?.error("Failed to encode structured data model: \(error)") + @Dependency(\.logger) var logger + logger.error("Failed to encode structured data model: \(error)") return .empty } } diff --git a/Sources/App/configure.swift b/Sources/App/configure.swift index c8a65988a..25798673b 100644 --- a/Sources/App/configure.swift +++ b/Sources/App/configure.swift @@ -12,6 +12,7 @@ // See the License for the specific language governing permissions and // limitations under the License. +import Dependencies import Fluent import FluentPostgresDriver import Vapor @@ -26,8 +27,9 @@ public func configure(_ app: Application) async throws -> String { let _ = Bundle(path: "/Applications/InjectionIII.app/Contents/Resources/macOSInjection.bundle")?.load() #endif + @Dependency(\.logger) var logger app.logger.component = "server" - Current.setLogger(app.logger) + logger.set(to: app.logger) // It will be tempting to uncomment/re-add these lines in the future. We should not enable // server-side compression as long as we pass requests through Cloudflare, which compresses diff --git a/Tests/AppTests/AppTestCase.swift b/Tests/AppTests/AppTestCase.swift index 487ea143b..5d61b3b4f 100644 --- a/Tests/AppTests/AppTestCase.swift +++ b/Tests/AppTests/AppTestCase.swift @@ -29,10 +29,8 @@ class AppTestCase: XCTestCase { try await super.setUp() app = try await setup(.testing) - // Always start with a baseline mock environment to avoid hitting live resources - Current = .mock(eventLoop: app.eventLoopGroup.next()) - - Current.setLogger(.init(label: "test", factory: { _ in logger })) + @Dependency(\.logger) var logger + logger.set(to: .init(label: "test", factory: { _ in self.logger })) } func setup(_ environment: Environment) async throws -> Application { diff --git a/Tests/AppTests/GitLiveTests.swift b/Tests/AppTests/GitLiveTests.swift index 4ded55d75..abe776a0d 100644 --- a/Tests/AppTests/GitLiveTests.swift +++ b/Tests/AppTests/GitLiveTests.swift @@ -42,14 +42,9 @@ class GitLiveTests: XCTestCase { try? Foundation.FileManager.default.removeItem(atPath: tempDir) } - let logger = CapturingLogger() - - override func setUp() { - Current.setLogger(.init(label: "test", factory: { _ in logger })) - } - override func invokeTest() { withDependencies { + $0.logger.log = { @Sendable _, _ in } $0.shell = .liveValue } operation: { super.invokeTest() diff --git a/Tests/AppTests/Mocks/AppEnvironment+mock.swift b/Tests/AppTests/Mocks/AppEnvironment+mock.swift deleted file mode 100644 index a15760ec1..000000000 --- a/Tests/AppTests/Mocks/AppEnvironment+mock.swift +++ /dev/null @@ -1,29 +0,0 @@ -// Copyright Dave Verwer, Sven A. Schmidt, and other contributors. -// -// Licensed under the Apache License, Version 2.0 (the "License"); -// you may not use this file except in compliance with the License. -// You may obtain a copy of the License at -// -// http://www.apache.org/licenses/LICENSE-2.0 -// -// Unless required by applicable law or agreed to in writing, software -// distributed under the License is distributed on an "AS IS" BASIS, -// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. -// See the License for the specific language governing permissions and -// limitations under the License. - -@testable import App - -import AsyncHTTPClient -import NIO -import Vapor - - -extension AppEnvironment { - static func mock(eventLoop: EventLoop) -> Self { - .init( - logger: { logger }, - setLogger: { logger in Self.logger = logger } - ) - } -}