File: TraceFromSignpostsCommand.swift

package info (click to toggle)
swiftlang 6.1.3-1
  • links: PTS, VCS
  • area: main
  • in suites: forky, sid
  • size: 2,791,532 kB
  • sloc: cpp: 9,901,743; ansic: 2,201,431; asm: 1,091,827; python: 308,252; objc: 82,166; f90: 80,126; lisp: 38,358; pascal: 25,559; sh: 20,429; ml: 5,058; perl: 4,745; makefile: 4,484; awk: 3,535; javascript: 3,018; xml: 918; fortran: 664; cs: 573; ruby: 396
file content (259 lines) | stat: -rw-r--r-- 8,199 bytes parent folder | download
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
256
257
258
259
//===----------------------------------------------------------------------===//
//
// This source file is part of the Swift.org open source project
//
// Copyright (c) 2014 - 2024 Apple Inc. and the Swift project authors
// Licensed under Apache License v2.0 with Runtime Library Exception
//
// See https://swift.org/LICENSE.txt for license information
// See https://swift.org/CONTRIBUTORS.txt for the list of Swift project authors
//
//===----------------------------------------------------------------------===//

#if compiler(>=6)
package import ArgumentParser
import Foundation
import RegexBuilder
import SwiftExtensions

import class TSCBasic.Process
#else
import ArgumentParser
import Foundation
import RegexBuilder
import SwiftExtensions

import class TSCBasic.Process
#endif

/// Shared instance of the regex that is used to extract Signpost lines from `log stream --signpost`.
fileprivate struct LogParseRegex {
  @MainActor static let shared = LogParseRegex()

  let dateComponent = Reference(Substring.self)
  let processIdComponent = Reference(Substring.self)
  let signpostIdComponent = Reference(Substring.self)
  let eventTypeComponent = Reference(Substring.self)
  let categoryComponent = Reference(Substring.self)
  let messageComponent = Reference(Substring.self)
  private(set) var regex:
    Regex<Regex<(Substring, Substring, Substring, Substring, Substring, Substring, Substring, Substring)>.RegexOutput>!

  private init() {
    regex = Regex {
      Capture(as: dateComponent) {
        #/[-0-9]+ [0-9:.-]+/#
      }
      " "
      #/[0-9a-fx]+/#  // Thread ID
      ZeroOrMore(.whitespace)
      "Signpost"
      ZeroOrMore(.whitespace)
      #/[0-9a-fx]+/#  // Activity
      ZeroOrMore(.whitespace)
      Capture(as: processIdComponent) {
        ZeroOrMore(.digit)
      }
      ZeroOrMore(.whitespace)
      ZeroOrMore(.digit)  // TTL
      ZeroOrMore(.whitespace)
      "[spid 0x"
      Capture(as: signpostIdComponent) {
        OneOrMore(.hexDigit)
      }
      ", process, "
      ZeroOrMore(.whitespace)
      Capture(as: eventTypeComponent) {
        #/(begin|event|end)/#
      }
      "]"
      ZeroOrMore(.whitespace)
      ZeroOrMore(.whitespace.inverted)  // Process name
      ZeroOrMore(.whitespace)
      "["
      ZeroOrMore(.any)  // subsystem
      ":"
      Capture(as: categoryComponent) {
        ZeroOrMore(.any)
      }
      "]"
      Capture(as: messageComponent) {
        ZeroOrMore(.any)
      }
    }
  }
}

/// A signpost event extracted from a log.
fileprivate struct Signpost {
  /// ID that identifies the signpost across the log.
  ///
  /// There might be multiple signposts with the same `signpostId` across multiple processes.
  struct ID: Hashable {
    let processId: Int
    let signpostId: Int
  }

  enum EventType: String {
    case begin
    case event
    case end
  }

  let date: Date
  let processId: Int
  let signpostId: Int
  let eventType: EventType
  let category: String
  let message: String

  var id: ID {
    ID(processId: processId, signpostId: signpostId)
  }

  @MainActor
  init?(logLine line: Substring) {
    let regex = LogParseRegex.shared
    let dateFormatter = DateFormatter()
    dateFormatter.dateFormat = "yyyy-MM-dd HH:mm:ss.SSSZ"
    guard let match = try? regex.regex.wholeMatch(in: line) else {
      return nil
    }
    guard let date = dateFormatter.date(from: String(match[regex.dateComponent])),
      let processId = Int(match[regex.processIdComponent]),
      let signpostId = Int(match[regex.signpostIdComponent], radix: 16),
      let eventType = Signpost.EventType(rawValue: String(match[regex.eventTypeComponent]))
    else {
      return nil
    }
    self.date = date
    self.processId = processId
    self.signpostId = signpostId
    self.eventType = eventType
    self.category = String(match[regex.categoryComponent])
    self.message = String(match[regex.messageComponent])
  }
}

/// A trace event in the *Trace Event Format* that can be opened using Perfetto.
/// https://docs.google.com/document/d/1CvAClvFfyA5R-PhYUmn5OOQtYMH4h6I0nSsKchNAySU/mobilebasic
fileprivate struct TraceEvent: Codable {
  enum EventType: String, Codable {
    case begin = "B"
    case end = "E"
  }

  /// The name of the event, as displayed in Trace Viewer
  let name: String?
  /// The event categories.
  ///
  /// This is a comma separated list of categories for the event.
  /// The categories can be used to hide events in the Trace Viewer UI.
  let cat: String

  /// The event type.
  ///
  /// This is a single character which changes depending on the type of event being output.
  let ph: EventType

  /// The process ID for the process that output this event.
  let pid: Int

  /// The thread ID for the thread that output this event.
  ///
  /// We use the signpost IDs as thread IDs to show each signpost on a single lane in the trace.
  let tid: Int

  /// The tracing clock timestamp of the event. The timestamps are provided at microsecond granularity.
  let ts: Double

  init(beginning signpost: Signpost) {
    self.name = signpost.message
    self.cat = signpost.category
    self.ph = .begin
    self.pid = signpost.processId
    self.tid = signpost.signpostId
    self.ts = signpost.date.timeIntervalSince1970 * 1_000_000
  }

  init(ending signpost: Signpost) {
    self.name = nil
    self.cat = signpost.category
    self.ph = .end
    self.pid = signpost.processId
    self.tid = signpost.signpostId
    self.ts = signpost.date.timeIntervalSince1970 * 1_000_000
  }
}

package struct TraceFromSignpostsCommand: AsyncParsableCommand {
  package static let configuration: CommandConfiguration = CommandConfiguration(
    commandName: "trace-from-signposts",
    abstract: "Generate a Trace Event Format file from signposts captured using OS Log",
    discussion: """
      Extracts signposts captured using 'log stream --signpost ..' and generates a trace file that can be opened using \
      Perfetto to visualize which requests were running concurrently.
      """
  )

  @Option(name: .customLong("log-file"), help: "The log file that was captured using 'log stream --signpost ...'")
  var logFile: String

  @Option(help: "The trace output file to generate")
  var output: String

  @Option(
    name: .customLong("category-filter"),
    help: "If specified, only include signposts from this logging category in the output file"
  )
  var categoryFilter: String?

  package init() {}

  private func traceEvents(from signpostsById: [Signpost.ID: [Signpost]]) -> [TraceEvent] {
    var traceEvents: [TraceEvent] = []
    for signposts in signpostsById.values {
      guard let begin = signposts.filter({ $0.eventType == .begin }).only else {
        continue
      }
      // Each begin event should to be paired with an end event.
      // If a begin event exists before the previous begin event is ended, a nested timeline is shown.
      // We display signpost events to last until the next signpost event.
      let events = signposts.filter { $0.eventType == .event }
      traceEvents.append(TraceEvent(beginning: begin))
      var hadPreviousEvent = false
      for event in events {
        if hadPreviousEvent {
          traceEvents.append(TraceEvent(ending: event))
        }
        hadPreviousEvent = true
        traceEvents.append(TraceEvent(beginning: event))
      }
      if let end = signposts.filter({ $0.eventType == .end }).only {
        if hadPreviousEvent {
          traceEvents.append(TraceEvent(ending: end))
        }
        traceEvents.append(TraceEvent(ending: end))
      }
    }
    return traceEvents
  }

  @MainActor
  package func run() async throws {
    let log = try String(contentsOf: URL(fileURLWithPath: logFile), encoding: .utf8)

    var signpostsById: [Signpost.ID: [Signpost]] = [:]
    for line in log.split(separator: "\n") {
      guard let signpost = Signpost(logLine: line) else {
        continue
      }
      if let categoryFilter, signpost.category != categoryFilter {
        continue
      }
      signpostsById[signpost.id, default: []].append(signpost)
    }
    let traceEvents = traceEvents(from: signpostsById)
    try JSONEncoder().encode(traceEvents).write(to: URL(fileURLWithPath: output))
  }
}