Wrap various convert subtasks in signpost intervals (#1112)

* Add a no-op shim for os.OSSignpost

* Bump platform versions to be able to use OSSignposter

* Fix deprecation warnings about UTType API

* Wrap various major convert tasks in signpost intervals

* Add a no-op shim for os.Logger

* Add support for interpolating errors in no-op log messages

* Address code review feedback:

- Add signpost intervals around a few more tasks

Author: d-ronnqvist

Package.swift

@@ -19,8 +19,8 @@ let swiftSettings: [SwiftSetting] = [
 let package = Package(
     name: "SwiftDocC",
     platforms: [
-        .macOS(.v10_15),
-        .iOS(.v13)
+        .macOS(.v12),
+        .iOS(.v15)
     ],
     products: [
         .library(

Sources/SwiftDocC/Infrastructure/ConvertActionConverter.swift

@@ -10,7 +10,16 @@
 
 import Foundation
 
+#if canImport(os)
+import os
+#endif
+
 package enum ConvertActionConverter {
+#if canImport(os)
+    static package let signposter = OSSignposter(subsystem: "org.swift.docc", category: "Convert")
+#else
+    static package let signposter = NoOpSignposterShim()
+#endif
 
     /// Converts the documentation bundle in the given context and passes its output to a given consumer.
     ///
@@ -30,8 +39,12 @@ package enum ConvertActionConverter {
         emitDigest: Bool,
         documentationCoverageOptions: DocumentationCoverageOptions
     ) throws -> [Problem] {
+        let signposter = Self.signposter
+        
         defer {
-            context.diagnosticEngine.flush()
+            signposter.withIntervalSignpost("Display diagnostics", id: signposter.makeSignpostID()) {
+                context.diagnosticEngine.flush()
+            }
         }
 
         let processingDurationMetric = benchmark(begin: Benchmark.Duration(id: "documentation-processing"))
@@ -47,7 +60,9 @@ package enum ConvertActionConverter {
         }
 
         // Precompute the render context
-        let renderContext = RenderContext(documentationContext: context, bundle: bundle)
+        let renderContext = signposter.withIntervalSignpost("Build RenderContext", id: signposter.makeSignpostID()) {
+            RenderContext(documentationContext: context, bundle: bundle)
+        }
         try outputConsumer.consume(renderReferenceStore: renderContext.store)
 
         // Copy images, sample files, and other static assets.
@@ -89,6 +104,8 @@ package enum ConvertActionConverter {
         let resultsSyncQueue = DispatchQueue(label: "Convert Serial Queue", qos: .unspecified, attributes: [])
         let resultsGroup = DispatchGroup()
 
+        let renderSignpostHandle = signposter.beginInterval("Render", id: signposter.makeSignpostID(), "Render \(context.knownPages.count) pages")
+        
         var conversionProblems: [Problem] = context.knownPages.concurrentPerform { identifier, results in
             // If cancelled skip all concurrent conversion work in this block.
             guard !Task.isCancelled else { return }
@@ -146,37 +163,45 @@ package enum ConvertActionConverter {
         // Wait for any concurrent updates to complete.
         resultsGroup.wait()
 
+        signposter.endInterval("Render", renderSignpostHandle)
+        
         guard !Task.isCancelled else { return [] }
 
         // Write various metadata
         if emitDigest {
-            do {
-                try outputConsumer.consume(linkableElementSummaries: linkSummaries)
-                try outputConsumer.consume(indexingRecords: indexingRecords)
-                try outputConsumer.consume(assets: assets)
-            } catch {
-                recordProblem(from: error, in: &conversionProblems, withIdentifier: "metadata")
+            signposter.withIntervalSignpost("Emit digest", id: signposter.makeSignpostID()) {
+                do {
+                    try outputConsumer.consume(linkableElementSummaries: linkSummaries)
+                    try outputConsumer.consume(indexingRecords: indexingRecords)
+                    try outputConsumer.consume(assets: assets)
+                } catch {
+                    recordProblem(from: error, in: &conversionProblems, withIdentifier: "metadata")
+                }
             }
         }
 
         if FeatureFlags.current.isExperimentalLinkHierarchySerializationEnabled {
-            do {
-                let serializableLinkInformation = try context.linkResolver.localResolver.prepareForSerialization(bundleID: bundle.id)
-                try outputConsumer.consume(linkResolutionInformation: serializableLinkInformation)
-                
-                if !emitDigest {
-                    try outputConsumer.consume(linkableElementSummaries: linkSummaries)
+            signposter.withIntervalSignpost("Serialize link hierarchy", id: signposter.makeSignpostID()) {
+                do {
+                    let serializableLinkInformation = try context.linkResolver.localResolver.prepareForSerialization(bundleID: bundle.id)
+                    try outputConsumer.consume(linkResolutionInformation: serializableLinkInformation)
+                    
+                    if !emitDigest {
+                        try outputConsumer.consume(linkableElementSummaries: linkSummaries)
+                    }
+                } catch {
+                    recordProblem(from: error, in: &conversionProblems, withIdentifier: "link-resolver")
                 }
-            } catch {
-                recordProblem(from: error, in: &conversionProblems, withIdentifier: "link-resolver")
             }
         }
 
         if emitDigest {
-            do {
-                try outputConsumer.consume(problems: context.problems + conversionProblems)
-            } catch {
-                recordProblem(from: error, in: &conversionProblems, withIdentifier: "problems")
+            signposter.withIntervalSignpost("Emit digest", id: signposter.makeSignpostID()) {
+                do {
+                    try outputConsumer.consume(problems: context.problems + conversionProblems)
+                } catch {
+                    recordProblem(from: error, in: &conversionProblems, withIdentifier: "problems")
+                }
             }
         }
 

Sources/SwiftDocC/Infrastructure/DocumentationContext.swift

@@ -83,6 +83,7 @@ public typealias BundleIdentifier = String
 /// - ``parents(of:)``
 ///
 public class DocumentationContext {
+    private let signposter = ConvertActionConverter.signposter
 
     /// An error that's encountered while interacting with a ``SwiftDocC/DocumentationContext``.
     public enum ContextError: DescribedError {
@@ -563,6 +564,11 @@ public class DocumentationContext {
      Attempt to resolve links in curation-only documentation, converting any ``TopicReferences`` from `.unresolved` to `.resolved` where possible.
      */
     private func resolveLinks(curatedReferences: Set<ResolvedTopicReference>, bundle: DocumentationBundle) {
+        let signpostHandle = signposter.beginInterval("Resolve links", id: signposter.makeSignpostID())
+        defer {
+            signposter.endInterval("Resolve links", signpostHandle)
+        }
+        
         let references = Array(curatedReferences)
         let results = Synchronized<[LinkResolveResult]>([])
         results.sync({ $0.reserveCapacity(references.count) })
@@ -708,6 +714,11 @@ public class DocumentationContext {
         tutorialArticles: [SemanticResult<TutorialArticle>],
         bundle: DocumentationBundle
     ) {
+        let signpostHandle = signposter.beginInterval("Resolve links", id: signposter.makeSignpostID())
+        defer {
+            signposter.endInterval("Resolve links", signpostHandle)
+        }
+        
         let sourceLanguages = soleRootModuleReference.map { self.sourceLanguages(for: $0) } ?? [.swift]
 
         // Tutorial table-of-contents
@@ -1147,6 +1158,11 @@ public class DocumentationContext {
     ) throws {
         // Making sure that we correctly let decoding memory get released, do not remove the autorelease pool.
         try autoreleasepool {
+            let signpostHandle = signposter.beginInterval("Register symbols", id: signposter.makeSignpostID())
+            defer {
+                signposter.endInterval("Register symbols", signpostHandle)
+            }
+            
             /// We need only unique relationships so we'll collect them in a set.
             var combinedRelationshipsBySelector = [UnifiedSymbolGraph.Selector: Set<SymbolGraph.Relationship>]()
             /// Also track the unique relationships across all languages and platforms
@@ -1157,7 +1173,9 @@ public class DocumentationContext {
             var moduleReferences = [String: ResolvedTopicReference]()
 
             // Build references for all symbols in all of this module's symbol graphs.
-            let symbolReferences = linkResolver.localResolver.referencesForSymbols(in: symbolGraphLoader.unifiedGraphs, bundle: bundle, context: self)
+            let symbolReferences = signposter.withIntervalSignpost("Disambiguate references") {
+                linkResolver.localResolver.referencesForSymbols(in: symbolGraphLoader.unifiedGraphs, bundle: bundle, context: self)
+            }
 
             // Set the index and cache storage capacity to avoid ad-hoc storage resizing.
             documentationCache.reserveCapacity(symbolReferences.count)
@@ -1223,7 +1241,9 @@ public class DocumentationContext {
                     let moduleSymbolReference = SymbolReference(moduleName, interfaceLanguages: moduleInterfaceLanguages, defaultSymbol: moduleSymbol)
                     moduleReference = ResolvedTopicReference(symbolReference: moduleSymbolReference, moduleName: moduleName, bundle: bundle)
 
-                    addSymbolsToTopicGraph(symbolGraph: unifiedSymbolGraph, url: fileURL, symbolReferences: symbolReferences, moduleReference: moduleReference)
+                    signposter.withIntervalSignpost("Add symbols to topic graph", id: signposter.makeSignpostID()) {
+                        addSymbolsToTopicGraph(symbolGraph: unifiedSymbolGraph, url: fileURL, symbolReferences: symbolReferences, moduleReference: moduleReference)
+                    }
 
                     // For inherited symbols we remove the source docs (if inheriting docs is disabled) before creating their documentation nodes.
                     for (_, relationships) in unifiedSymbolGraph.relationshipsByLanguage {
@@ -1375,15 +1395,17 @@ public class DocumentationContext {
             )
 
             // Parse and prepare the nodes' content concurrently.
-            let updatedNodes = Array(documentationCache.symbolReferences).concurrentMap { finalReference in
-                // Match the symbol's documentation extension and initialize the node content.
-                let match = uncuratedDocumentationExtensions[finalReference]
-                let updatedNode = nodeWithInitializedContent(reference: finalReference, match: match)
-                
-                return ((
-                    node: updatedNode,
-                    matchedArticleURL: match?.source
-                ))
+            let updatedNodes = signposter.withIntervalSignpost("Parse symbol markup", id: signposter.makeSignpostID()) {
+                Array(documentationCache.symbolReferences).concurrentMap { finalReference in
+                    // Match the symbol's documentation extension and initialize the node content.
+                    let match = uncuratedDocumentationExtensions[finalReference]
+                    let updatedNode = nodeWithInitializedContent(reference: finalReference, match: match)
+                    
+                    return ((
+                        node: updatedNode,
+                        matchedArticleURL: match?.source
+                    ))
+                }
             }
 
             // Update cache with up-to-date nodes
@@ -2177,9 +2199,16 @@ public class DocumentationContext {
             )
 
             do {
-                try symbolGraphLoader.loadAll()
-                let pathHierarchy = PathHierarchy(symbolGraphLoader: symbolGraphLoader, bundleName: urlReadablePath(bundle.displayName), knownDisambiguatedPathComponents: configuration.convertServiceConfiguration.knownDisambiguatedSymbolPathComponents)
-                hierarchyBasedResolver = PathHierarchyBasedLinkResolver(pathHierarchy: pathHierarchy)
+                try signposter.withIntervalSignpost("Load symbols", id: signposter.makeSignpostID()) {
+                    try symbolGraphLoader.loadAll()
+                }
+                hierarchyBasedResolver = signposter.withIntervalSignpost("Build PathHierarchy", id: signposter.makeSignpostID()) {
+                    PathHierarchyBasedLinkResolver(pathHierarchy: PathHierarchy(
+                        symbolGraphLoader: symbolGraphLoader,
+                        bundleName: urlReadablePath(bundle.displayName),
+                        knownDisambiguatedPathComponents: configuration.convertServiceConfiguration.knownDisambiguatedSymbolPathComponents
+                    ))
+                }
             } catch {
                 // Pipe the error out of the dispatch queue.
                 discoveryError.sync({
@@ -2191,7 +2220,9 @@ public class DocumentationContext {
         // First, all the resources are added since they don't reference anything else.
         discoveryGroup.async(queue: discoveryQueue) { [unowned self] in
             do {
-                try self.registerMiscResources(from: bundle)
+                try signposter.withIntervalSignpost("Load resources", id: signposter.makeSignpostID()) {
+                    try self.registerMiscResources(from: bundle)
+                }
             } catch {
                 // Pipe the error out of the dispatch queue.
                 discoveryError.sync({
@@ -2215,7 +2246,9 @@ public class DocumentationContext {
 
         discoveryGroup.async(queue: discoveryQueue) { [unowned self] in
             do {
-                result = try self.registerDocuments(from: bundle)
+                result = try signposter.withIntervalSignpost("Load documents", id: signposter.makeSignpostID()) {
+                    try self.registerDocuments(from: bundle)
+                }
             } catch {
                 // Pipe the error out of the dispatch queue.
                 discoveryError.sync({
@@ -2226,7 +2259,9 @@ public class DocumentationContext {
 
         discoveryGroup.async(queue: discoveryQueue) { [unowned self] in
             do {
-                try linkResolver.loadExternalResolvers(dependencyArchives: configuration.externalDocumentationConfiguration.dependencyArchives)
+                try signposter.withIntervalSignpost("Load external resolvers", id: signposter.makeSignpostID()) {
+                    try linkResolver.loadExternalResolvers(dependencyArchives: configuration.externalDocumentationConfiguration.dependencyArchives)
+                }
             } catch {
                 // Pipe the error out of the dispatch queue.
                 discoveryError.sync({
@@ -2361,7 +2396,9 @@ public class DocumentationContext {
         try shouldContinueRegistration()
 
         // Fourth, automatically curate all symbols that haven't been curated manually
-        let automaticallyCurated = autoCurateSymbolsInTopicGraph()
+        let automaticallyCurated = signposter.withIntervalSignpost("Auto-curate symbols ", id: signposter.makeSignpostID()) {
+            autoCurateSymbolsInTopicGraph()
+        }
 
         // Crawl the rest of the symbols that haven't been crawled so far in hierarchy pre-order.
         allCuratedReferences = try crawlSymbolCuration(in: automaticallyCurated.map(\.symbol), bundle: bundle, initial: allCuratedReferences)
@@ -2407,7 +2444,9 @@ public class DocumentationContext {
         }
 
         // Seventh, the complete topic graph—with all nodes and all edges added—is analyzed.
-        topicGraphGlobalAnalysis()
+        signposter.withIntervalSignpost("Analyze topic graph", id: signposter.makeSignpostID()) {
+            topicGraphGlobalAnalysis()
+        }
 
         preResolveModuleNames()
     }
@@ -2606,6 +2645,11 @@ public class DocumentationContext {
     /// - Returns: The references of all the symbols that were curated.
     @discardableResult
     func crawlSymbolCuration(in references: [ResolvedTopicReference], bundle: DocumentationBundle, initial: Set<ResolvedTopicReference> = []) throws -> Set<ResolvedTopicReference> {
+        let signpostHandle = signposter.beginInterval("Curate symbols", id: signposter.makeSignpostID())
+        defer {
+            signposter.endInterval("Curate symbols", signpostHandle)
+        }
+        
         var crawler = DocumentationCurator(in: self, bundle: bundle, initial: initial)
 
         for reference in references {

Sources/SwiftDocC/Infrastructure/Symbol Graph/SymbolGraphLoader.swift

@@ -54,6 +54,8 @@ struct SymbolGraphLoader {
     ///
     /// - Throws: If loading and decoding any of the symbol graph files throws, this method re-throws one of the encountered errors.
     mutating func loadAll() throws {
+        let signposter = ConvertActionConverter.signposter
+        
         let loadingLock = Lock()
 
         var loadedGraphs = [URL: (usesExtensionSymbolFormat: Bool?, graph: SymbolKit.SymbolGraph)]()
@@ -118,6 +120,8 @@ struct SymbolGraphLoader {
         }
         #endif
 
+        let numberOfSymbolGraphs = bundle.symbolGraphURLs.count
+        let decodeSignpostHandle = signposter.beginInterval("Decode symbol graphs", id: signposter.makeSignpostID(), "Decode \(numberOfSymbolGraphs) symbol graphs")
         switch decodingStrategy {
         case .concurrentlyAllFiles:
             // Concurrently load and decode all symbol graphs
@@ -127,12 +131,14 @@ struct SymbolGraphLoader {
             // Serially load and decode all symbol graphs, each one in concurrent batches.
             bundle.symbolGraphURLs.forEach(loadGraphAtURL)
         }
+        signposter.endInterval("Decode symbol graphs", decodeSignpostHandle)
 
         // define an appropriate merging strategy based on the graph formats
         let foundGraphUsingExtensionSymbolFormat = loadedGraphs.values.map(\.usesExtensionSymbolFormat).contains(true)
 
         let usingExtensionSymbolFormat = foundGraphUsingExtensionSymbolFormat
-                
+        
+        let mergeSignpostHandle = signposter.beginInterval("Build unified symbol graph", id: signposter.makeSignpostID())
         let graphLoader = GraphCollector(extensionGraphAssociationStrategy: usingExtensionSymbolFormat ? .extendingGraph : .extendedGraph)
 
         // feed the loaded graphs into the `graphLoader`
@@ -150,7 +156,13 @@ struct SymbolGraphLoader {
         (self.unifiedGraphs, self.graphLocations) = graphLoader.finishLoading(
             createOverloadGroups: FeatureFlags.current.isExperimentalOverloadedSymbolPresentationEnabled
         )
+        signposter.endInterval("Build unified symbol graph", mergeSignpostHandle)
 
+        let availabilitySignpostHandle = signposter.beginInterval("Add missing availability", id: signposter.makeSignpostID())
+        defer {
+            signposter.endInterval("Add missing availability", availabilitySignpostHandle)
+        }
+        
         for var unifiedGraph in unifiedGraphs.values {
             var defaultUnavailablePlatforms = [PlatformName]()
             var defaultAvailableInformation = [DefaultAvailability.ModuleAvailability]()

Sources/SwiftDocC/Servers/FileServer.swift

@@ -13,6 +13,9 @@ import SymbolKit
 #if canImport(FoundationNetworking)
 import FoundationNetworking
 #endif
+#if canImport(UniformTypeIdentifiers)
+import UniformTypeIdentifiers
+#endif
 #if os(Windows)
 import WinSDK
 #endif
@@ -116,15 +119,7 @@ public class FileServer {
 
         #if os(macOS)
 
-        let unmanagedFileUTI = UTTypeCreatePreferredIdentifierForTag(kUTTagClassFilenameExtension, ext as CFString, nil)
-        guard let fileUTI = unmanagedFileUTI?.takeRetainedValue() else {
-            return defaultMimeType
-        }
-        guard let mimeType = UTTypeCopyPreferredTagWithClass (fileUTI, kUTTagClassMIMEType)?.takeRetainedValue() else {
-            return defaultMimeType
-        }
-        
-        return (mimeType as NSString) as String
+        return UTType(filenameExtension: ext)?.preferredMIMEType ?? defaultMimeType
 
         #elseif os(Windows)