Skip to content

Commit a6a27a8

Browse files
committed
Write log messages to files on Linux
Instead of logging to `stderr`, write log messages to files in `/var/log/sourcekit-lsp/sourcekit-lsp-<pid>.log`. This allows us to retrieve the log messages from `sourcekit-lsp diagnose`. We should be able to expand this to also write to log files on Windows but I still need to figure out what an appropriate log directory might be. That will be a follow-up PR. Fixes swiftlang#1286 rdar://127138318
1 parent 9c13dbb commit a6a27a8

File tree

7 files changed

+267
-33
lines changed

7 files changed

+267
-33
lines changed

Package.swift

+2-1
Original file line numberDiff line numberDiff line change
@@ -161,7 +161,8 @@ let package = Package(
161161
.target(
162162
name: "LSPLogging",
163163
dependencies: [
164-
.product(name: "Crypto", package: "swift-crypto")
164+
"SwiftExtensions",
165+
.product(name: "Crypto", package: "swift-crypto"),
165166
],
166167
exclude: ["CMakeLists.txt"],
167168
swiftSettings: lspLoggingSwiftSettings + [.enableExperimentalFeature("StrictConcurrency")]

Sources/Diagnose/DiagnoseCommand.swift

+29-1
Original file line numberDiff line numberDiff line change
@@ -232,6 +232,34 @@ public struct DiagnoseCommand: AsyncParsableCommand {
232232
#endif
233233
}
234234

235+
@MainActor
236+
private func addNonDarwinLogs(toBundle bundlePath: URL) async throws {
237+
reportProgress(.collectingLogMessages(progress: 0), message: "Collecting log files")
238+
239+
let destinationDir = bundlePath.appendingPathComponent("logs")
240+
try FileManager.default.createDirectory(at: destinationDir, withIntermediateDirectories: true)
241+
242+
let enumerator = FileManager.default.enumerator(
243+
at: URL(fileURLWithPath: "/var/log/sourcekit-lsp"),
244+
includingPropertiesForKeys: nil
245+
)
246+
while let fileUrl = enumerator?.nextObject() as? URL {
247+
guard fileUrl.lastPathComponent.hasPrefix("sourcekit-lsp") else {
248+
continue
249+
}
250+
try? FileManager.default.copyItem(
251+
at: fileUrl,
252+
to: destinationDir.appendingPathComponent(fileUrl.lastPathComponent)
253+
)
254+
}
255+
}
256+
257+
@MainActor
258+
private func addLogs(toBundle bundlePath: URL) async throws {
259+
try await addNonDarwinLogs(toBundle: bundlePath)
260+
try await addOsLog(toBundle: bundlePath)
261+
}
262+
235263
@MainActor
236264
private func addCrashLogs(toBundle bundlePath: URL) throws {
237265
#if os(macOS)
@@ -328,7 +356,7 @@ public struct DiagnoseCommand: AsyncParsableCommand {
328356
await orPrintError { try addCrashLogs(toBundle: bundlePath) }
329357
}
330358
if components.isEmpty || components.contains(.logs) {
331-
await orPrintError { try await addOsLog(toBundle: bundlePath) }
359+
await orPrintError { try await addLogs(toBundle: bundlePath) }
332360
}
333361
if components.isEmpty || components.contains(.swiftVersions) {
334362
await orPrintError { try await addSwiftVersion(toBundle: bundlePath) }

Sources/LSPLogging/CMakeLists.txt

+2
Original file line numberDiff line numberDiff line change
@@ -5,10 +5,12 @@ add_library(LSPLogging STATIC
55
LoggingScope.swift
66
NonDarwinLogging.swift
77
OrLog.swift
8+
SetGlobalLogFileHandler.swift
89
SplitLogMessage.swift)
910
set_target_properties(LSPLogging PROPERTIES
1011
INTERFACE_INCLUDE_DIRECTORIES ${CMAKE_Swift_MODULE_DIRECTORY})
1112
target_link_libraries(LSPLogging PRIVATE
13+
SwiftExtensions
1214
$<$<NOT:$<PLATFORM_ID:Darwin>>:Foundation>)
1315
target_link_libraries(LSPLogging PUBLIC
1416
Crypto)

Sources/LSPLogging/NonDarwinLogging.swift

+21-8
Original file line numberDiff line numberDiff line change
@@ -11,6 +11,7 @@
1111
//===----------------------------------------------------------------------===//
1212

1313
import Foundation
14+
import SwiftExtensions
1415

1516
// MARK: - Log settings
1617

@@ -261,22 +262,34 @@ private let dateFormatter = {
261262
return dateFormatter
262263
}()
263264

265+
/// Actor that protects `logHandler`
266+
@globalActor
267+
actor LogHandlerActor {
268+
static var shared: LogHandlerActor = LogHandlerActor()
269+
}
270+
271+
/// The handler that is called to log a message from `NonDarwinLogger` unless `overrideLogHandler` is set on the logger.
272+
@LogHandlerActor
273+
var logHandler: @Sendable (String) async -> Void = { fputs($0 + "\n", stderr) }
274+
264275
/// The queue on which we log messages.
265276
///
266277
/// A global queue since we create and discard loggers all the time.
267-
private let loggingQueue: DispatchQueue = DispatchQueue(label: "loggingQueue", qos: .utility)
278+
private let loggingQueue = AsyncQueue<Serial>()
268279

269280
/// A logger that is designed to be API-compatible with `os.Logger` for all uses
270281
/// in sourcekit-lsp.
271282
///
272283
/// This logger is used to log messages to stderr on platforms where OSLog is
273284
/// not available.
285+
///
286+
/// `overrideLogHandler` allows capturing of the logged messages for testing purposes.
274287
public struct NonDarwinLogger: Sendable {
275288
private let subsystem: String
276289
private let category: String
277290
private let logLevel: NonDarwinLogLevel
278291
private let privacyLevel: NonDarwinLogPrivacy
279-
private let logHandler: @Sendable (String) -> Void
292+
private let overrideLogHandler: (@Sendable (String) -> Void)?
280293

281294
/// - Parameters:
282295
/// - subsystem: See os.Logger
@@ -291,13 +304,13 @@ public struct NonDarwinLogger: Sendable {
291304
category: String,
292305
logLevel: NonDarwinLogLevel? = nil,
293306
privacyLevel: NonDarwinLogPrivacy? = nil,
294-
logHandler: @escaping @Sendable (String) -> Void = { fputs($0 + "\n", stderr) }
307+
overrideLogHandler: (@Sendable (String) -> Void)? = nil
295308
) {
296309
self.subsystem = subsystem
297310
self.category = category
298311
self.logLevel = logLevel ?? LogConfig.logLevel
299312
self.privacyLevel = privacyLevel ?? LogConfig.privacyLevel
300-
self.logHandler = logHandler
313+
self.overrideLogHandler = overrideLogHandler
301314
}
302315

303316
/// Logs the given message at the given level.
@@ -310,7 +323,7 @@ public struct NonDarwinLogger: Sendable {
310323
) {
311324
guard level >= self.logLevel else { return }
312325
let date = Date()
313-
loggingQueue.async {
326+
loggingQueue.async(priority: .utility) { @LogHandlerActor in
314327
// Truncate log message after 10.000 characters to avoid flooding the log with huge log messages (eg. from a
315328
// sourcekitd response). 10.000 characters was chosen because it seems to fit the result of most sourcekitd
316329
// responses that are not generated interface or global completion results (which are a lot bigger).
@@ -321,7 +334,7 @@ public struct NonDarwinLogger: Sendable {
321334
message = message.prefix(10_000) + "..."
322335
}
323336
// Start each log message with `[org.swift.sourcekit-lsp` so that it’s easy to split the log to the different messages
324-
logHandler(
337+
await (overrideLogHandler ?? logHandler)(
325338
"""
326339
[\(subsystem):\(category)] \(level) \(dateFormatter.string(from: date))
327340
\(message)
@@ -361,8 +374,8 @@ public struct NonDarwinLogger: Sendable {
361374
/// Useful for testing to make sure all asynchronous log calls have actually
362375
/// written their data.
363376
@_spi(Testing)
364-
public static func flush() {
365-
loggingQueue.sync {}
377+
public static func flush() async {
378+
await loggingQueue.async {}.value
366379
}
367380

368381
public func makeSignposter() -> NonDarwinSignposter {
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,174 @@
1+
//===----------------------------------------------------------------------===//
2+
//
3+
// This source file is part of the Swift.org open source project
4+
//
5+
// Copyright (c) 2014 - 2023 Apple Inc. and the Swift project authors
6+
// Licensed under Apache License v2.0 with Runtime Library Exception
7+
//
8+
// See https://swift.org/LICENSE.txt for license information
9+
// See https://swift.org/CONTRIBUTORS.txt for the list of Swift project authors
10+
//
11+
//===----------------------------------------------------------------------===//
12+
13+
import Foundation
14+
import RegexBuilder
15+
16+
#if !canImport(os) || SOURCEKITLSP_FORCE_NON_DARWIN_LOGGER
17+
fileprivate struct FailedToCreateFileError: Error, CustomStringConvertible {
18+
let logFile: URL
19+
20+
var description: String {
21+
return "Failed to create log file at \(logFile)"
22+
}
23+
}
24+
/// Creates a file handle that can write to the log file at `logFilePath`.
25+
///
26+
/// If creation of the file handle fails (eg. because the file is not writable), return `nil`.
27+
private func createLogFileHandle(at logFile: URL) throws -> FileHandle {
28+
if !FileManager.default.fileExists(atPath: logFile.path) {
29+
guard FileManager.default.createFile(atPath: logFile.path, contents: nil) else {
30+
throw FailedToCreateFileError(logFile: logFile)
31+
}
32+
}
33+
let logFileHandle = try FileHandle(forWritingTo: logFile)
34+
try logFileHandle.seekToEnd()
35+
return logFileHandle
36+
}
37+
38+
/// The number of log calls that have been made to the log file handler.
39+
///
40+
/// See comment in `logImpl`.
41+
@LogHandlerActor
42+
fileprivate var logCallsCounter = 0
43+
44+
/// Log the given message to the given log file handle.
45+
///
46+
/// Occasionally check if the log file exceeds the target log size. If this is the case, truncate the beginning of the
47+
/// log to reduce the log size.
48+
@LogHandlerActor
49+
private func logToFile(message: String, logFileHandle: FileHandle, logFile: URL, targetLogSize: Int) throws {
50+
guard let data = message.data(using: .utf8) else {
51+
fputs(
52+
"""
53+
Failed to convert log message to UTF-8 data
54+
\(message)
55+
56+
""",
57+
stderr
58+
)
59+
return
60+
}
61+
try logFileHandle.write(contentsOf: data)
62+
logCallsCounter &+= 1
63+
64+
// Every `targetLogSize / 10,000` calls, check if the log file exceeds the maximum size. If this is the case, reduce
65+
// the log file to 80% of the maximum size by trimming the beginning to allow room for some more log messages.
66+
// 10,000 is the maximum log message size (capped by `NonDarwinLogger.log`). This means that the log will never exceed
67+
// the target size by more than 80%: The log might be 80% of the maximum size to start with and we might add up to
68+
// `targetLogSize` bytes to it until the next check.
69+
// For a target log size of 5MB, this means that we check the log for its size every 500 log calls.
70+
if logCallsCounter.isMultiple(of: targetLogSize / 10_000),
71+
let size = try? FileManager.default.attributesOfItem(atPath: logFile.path)[.size] as? Int, size > targetLogSize,
72+
let currentContents = try? Data(contentsOf: logFile)
73+
{
74+
let trimmedLogContents = currentContents[
75+
currentContents.index(currentContents.endIndex, offsetBy: -targetLogSize / 10 * 8)...
76+
]
77+
try trimmedLogContents.write(to: logFile)
78+
try logFileHandle.seekToEnd()
79+
}
80+
}
81+
82+
/// If the file at the given path is writable, redirect log messages handled by `NonDarwinLogHandler` to the given file.
83+
///
84+
/// Occasionally checks that the log does not exceed `targetLogSize` (in bytes) and truncates the beginning of the log
85+
/// when it does.
86+
@LogHandlerActor
87+
private func setUpGlobalLogFileHandlerImpl(logFileDirectory: URL, targetLogSize: Int) {
88+
let logFile: URL
89+
let logFileHandle: FileHandle
90+
do {
91+
try FileManager.default.createDirectory(at: logFileDirectory, withIntermediateDirectories: true)
92+
// Name must match the regex in `cleanOldLogFiles` and the prefix in `DiagnoseCommand.addNonDarwinLogs`.
93+
logFile = logFileDirectory.appendingPathComponent("sourcekit-lsp-\(ProcessInfo.processInfo.processIdentifier).log")
94+
logFileHandle = try createLogFileHandle(at: logFile)
95+
} catch {
96+
// We still have a log handler that logs to stderr. So we can log any errors during log file handle creation to it.
97+
logger.error("Failed to create log file in \(logFileDirectory): \(error.forLogging)")
98+
return
99+
}
100+
101+
logHandler = { @LogHandlerActor message in
102+
do {
103+
try logToFile(
104+
message: message,
105+
logFileHandle: logFileHandle,
106+
logFile: logFile,
107+
targetLogSize: targetLogSize
108+
)
109+
} catch {
110+
fputs(
111+
"""
112+
Failed to write message to log file: \(error)
113+
\(message)
114+
115+
""",
116+
stderr
117+
)
118+
}
119+
}
120+
}
121+
122+
private func cleanOldLogFilesImpl(logFileDirectory: URL) {
123+
let enumerator = FileManager.default.enumerator(at: logFileDirectory, includingPropertiesForKeys: nil)
124+
while let url = enumerator?.nextObject() as? URL {
125+
let name = url.lastPathComponent
126+
let regex = Regex {
127+
"sourcekit-lsp-"
128+
Capture(ZeroOrMore(.digit))
129+
".log"
130+
}
131+
guard let match = name.matches(of: regex).only, let pid = Int32(match.1) else {
132+
continue
133+
}
134+
if kill(pid, 0) == 0 {
135+
// Process that owns this log file is still alive. Don't delete
136+
continue
137+
}
138+
guard
139+
let modificationDate = orLog(
140+
"Getting mtime of old log file",
141+
{ try FileManager.default.attributesOfItem(atPath: url.path)[.modificationDate] }
142+
) as? Date,
143+
Date().timeIntervalSince(modificationDate) > 60 * 60
144+
else {
145+
// File has been modified in the last hour. Don't delete it because it's useful to diagnose issues after
146+
// sourcekit-lsp has exited.
147+
continue
148+
}
149+
orLog("Deleting old log file") { try FileManager.default.removeItem(at: url) }
150+
}
151+
}
152+
#endif
153+
154+
/// If the file at the given path is writable, redirect log messages handled by `NonDarwinLogHandler` to the given file.
155+
///
156+
/// Occasionally checks that the log does not exceed `targetLogSize` (in bytes) and truncates the beginning of the log
157+
/// when it does.
158+
///
159+
/// No-op when using OSLog.
160+
public func setUpGlobalLogFileHandler(logFileDirectory: URL, targetLogSize: Int) async {
161+
#if !canImport(os) || SOURCEKITLSP_FORCE_NON_DARWIN_LOGGER
162+
await setUpGlobalLogFileHandlerImpl(logFileDirectory: logFileDirectory, targetLogSize: targetLogSize)
163+
#endif
164+
}
165+
166+
/// Deletes all sourcekit-lsp log files in `logFilesDirectory` that are not associated with a running process and that
167+
/// haven't been modified within the last hour.
168+
///
169+
/// No-op when using OSLog.
170+
public func cleanOldLogFiles(logFileDirectory: URL) {
171+
#if !canImport(os) || SOURCEKITLSP_FORCE_NON_DARWIN_LOGGER
172+
cleanOldLogFilesImpl(logFileDirectory: logFileDirectory)
173+
#endif
174+
}

Sources/sourcekit-lsp/SourceKitLSP.swift

+16
Original file line numberDiff line numberDiff line change
@@ -242,6 +242,22 @@ struct SourceKitLSP: AsyncParsableCommand {
242242

243243
let realStdoutHandle = FileHandle(fileDescriptor: realStdout, closeOnDealloc: false)
244244

245+
// When we're using `NonDarwinLogger`, try logging to `/var/log/sourcekit-lsp.log`. If we're on Darwin, we log to
246+
// OSLog and setting the log handler and cleaning old log files are no-ops.
247+
// If the log file cannot be created, continues logging to stderr as a fallback.
248+
let targetLogSize =
249+
if let str = ProcessInfo.processInfo.environment["SOURCEKIT_LSP_TARGET_LOG_SIZE"], let targetLogSize = Int(str) {
250+
targetLogSize
251+
} else {
252+
5_000_000
253+
}
254+
if targetLogSize > 0 {
255+
// Directory should match the directory we are searching for logs in `DiagnoseCommand.addNonDarwinLogs`.
256+
let logFileDirectoryURL = URL(fileURLWithPath: "/var/log/sourcekit-lsp")
257+
await setUpGlobalLogFileHandler(logFileDirectory: logFileDirectoryURL, targetLogSize: targetLogSize)
258+
cleanOldLogFiles(logFileDirectory: logFileDirectoryURL)
259+
}
260+
245261
let clientConnection = JSONRPCConnection(
246262
name: "client",
247263
protocol: MessageRegistry.lspProtocol,

0 commit comments

Comments
 (0)