Skip to content

When sourcekitd crashes, log the file contents with which it crashed and the request #933

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 1 commit into from
Oct 31, 2023
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions Sources/LSPLogging/CMakeLists.txt
Original file line number Diff line number Diff line change
Expand Up @@ -5,6 +5,7 @@ add_library(LSPLogging STATIC
LoggingScope.swift
NonDarwinLogging.swift
OrLog.swift
SplitLogMessage.swift
)
set_target_properties(LSPLogging PROPERTIES
INTERFACE_INCLUDE_DIRECTORIES ${CMAKE_Swift_MODULE_DIRECTORY})
Expand Down
30 changes: 30 additions & 0 deletions Sources/LSPLogging/SplitLogMessage.swift
Original file line number Diff line number Diff line change
@@ -0,0 +1,30 @@
//===----------------------------------------------------------------------===//
//
// This source file is part of the Swift.org open source project
//
// Copyright (c) 2014 - 2023 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
//
//===----------------------------------------------------------------------===//

/// Splits `message` on newline characters such that each chunk is at most `maxChunkSize` bytes long.
///
/// The intended use case for this is to split compiler arguments into multiple chunks so that each chunk doesn't exceed
/// the maximum message length of `os_log` and thus won't get truncated.
///
/// - Note: This will only split along newline boundary. If a single line is longer than `maxChunkSize`, it won't be
/// split. This is fine for compiler argument splitting since a single argument is rarely longer than 800 characters.
public func splitLongMultilineMessage(message: String, maxChunkSize: Int = 800) -> [String] {
var chunks: [String] = []
for line in message.split(separator: "\n", omittingEmptySubsequences: false) {
if let lastChunk = chunks.last, lastChunk.utf8.count + line.utf8.count < maxChunkSize {
chunks[chunks.count - 1] += "\n" + line
} else {
chunks.append(String(line))
}
}
return chunks
}
21 changes: 1 addition & 20 deletions Sources/SKCore/BuildSystemManager.swift
Original file line number Diff line number Diff line change
Expand Up @@ -325,7 +325,7 @@ fileprivate actor BuildSettingsLogger {
\(settings.workingDirectory ?? "<nil>")
"""

let chunks = splitLongMultilineMessage(message: log, maxChunkSize: 800)
let chunks = splitLongMultilineMessage(message: log)
for (index, chunk) in chunks.enumerated() {
logger.log(
"""
Expand All @@ -335,23 +335,4 @@ fileprivate actor BuildSettingsLogger {
)
}
}

/// Splits `message` on newline characters such that each chunk is at most `maxChunkSize` bytes long.
///
/// The intended use case for this is to split compiler arguments into multiple chunks so that each chunk doesn't exceed
/// the maximum message length of `os_log` and thus won't get truncated.
///
/// - Note: This will only split along newline boundary. If a single line is longer than `maxChunkSize`, it won't be
/// split. This is fine for compiler argument splitting since a single argument is rarely longer than 800 characters.
private func splitLongMultilineMessage(message: String, maxChunkSize: Int) -> [String] {
var chunks: [String] = []
for line in message.split(separator: "\n", omittingEmptySubsequences: false) {
if let lastChunk = chunks.last, lastChunk.utf8.count + line.utf8.count < maxChunkSize {
chunks[chunks.count - 1] += "\n" + line
} else {
chunks.append(String(line))
}
}
return chunks
}
}
28 changes: 24 additions & 4 deletions Sources/SourceKitD/SourceKitD.swift
Original file line number Diff line number Diff line change
Expand Up @@ -65,7 +65,11 @@ extension SourceKitD {

// MARK: - Convenience API for requests.

public func send(_ req: SKDRequestDictionary) async throws -> SKDResponseDictionary {
/// - Parameters:
/// - req: The request to send to sourcekitd.
/// - fileContents: The contents of the file that the request operates on. If sourcekitd crashes, the file contents
/// will be logged.
public func send(_ req: SKDRequestDictionary, fileContents: String?) async throws -> SKDResponseDictionary {
logRequest(req)

let signposter = logger.makeSignposter()
Expand All @@ -86,6 +90,24 @@ extension SourceKitD {

guard let dict = sourcekitdResponse.value else {
signposter.endInterval("sourcekitd-request", signposterState, "Error")
if sourcekitdResponse.error == .connectionInterrupted {
let log = """
Request:
\(req.description)

File contents:
\(fileContents ?? "<nil>")
"""
let chunks = splitLongMultilineMessage(message: log)
for (index, chunk) in chunks.enumerated() {
logger.fault(
"""
sourcekitd crashed (\(index + 1)/\(chunks.count))
\(chunk)
"""
)
}
Comment on lines +102 to +109
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

If OSLog treats this as private (which I believe is the default?), will we just log multiple sourcekitd crashed lines with redacted chunks?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yes, we will. It’s a big unfortunate but I don’t have any better idea.

}
throw sourcekitdResponse.error!
}

Expand All @@ -95,9 +117,7 @@ extension SourceKitD {
}

private func logRequest(_ request: SKDRequestDictionary) {
// FIXME: Ideally we could log the request key here at the info level but the dictionary is
// readonly.
logger.log(
logger.info(
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

What's default vs info? The docs weren't particularly illuminating.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ah, so persisted vs not 👍

"""
Sending sourcekitd request:
\(request.forLogging)
Expand Down
7 changes: 1 addition & 6 deletions Sources/SourceKitLSP/SourceKitServer.swift
Original file line number Diff line number Diff line change
Expand Up @@ -666,12 +666,7 @@ extension SourceKitServer: MessageHandler {
}

private func handleImpl(_ notification: some NotificationType, from clientID: ObjectIdentifier) async {
logger.log(
"""
Received notification
\(notification.forLogging)
"""
)
logger.log("Received notification: \(notification.forLogging)")

switch notification {
case let notification as InitializedNotification:
Expand Down
6 changes: 3 additions & 3 deletions Sources/SourceKitLSP/Swift/CodeCompletionSession.swift
Original file line number Diff line number Diff line change
Expand Up @@ -197,7 +197,7 @@ class CodeCompletionSession {
req[keys.compilerargs] = compileCommand.compilerArgs
}

let dict = try await sourcekitd.send(req)
let dict = try await sourcekitd.send(req, fileContents: snapshot.text)
self.state = .open

guard let completions: SKDResponseArray = dict[keys.results] else {
Expand Down Expand Up @@ -230,7 +230,7 @@ class CodeCompletionSession {
req[keys.name] = uri.pseudoPath
req[keys.codecomplete_options] = optionsDictionary(filterText: filterText, options: options)

let dict = try await sourcekitd.send(req)
let dict = try await sourcekitd.send(req, fileContents: snapshot.text)
guard let completions: SKDResponseArray = dict[keys.results] else {
return CompletionList(isIncomplete: false, items: [])
}
Expand Down Expand Up @@ -275,7 +275,7 @@ class CodeCompletionSession {
req[keys.offset] = self.utf8StartOffset
req[keys.name] = self.snapshot.uri.pseudoPath
logger.info("Closing code completion session: \(self, privacy: .private)")
_ = try? await sourcekitd.send(req)
_ = try? await sourcekitd.send(req, fileContents: nil)
self.state = .closed
}
}
Expand Down
2 changes: 1 addition & 1 deletion Sources/SourceKitLSP/Swift/CursorInfo.swift
Original file line number Diff line number Diff line change
Expand Up @@ -107,7 +107,7 @@ extension SwiftLanguageServer {

appendAdditionalParameters?(skreq)

let dict = try await self.sourcekitd.send(skreq)
let dict = try await self.sourcekitd.send(skreq, fileContents: snapshot.text)

guard let kind: sourcekitd_uid_t = dict[keys.kind] else {
// Nothing to report.
Expand Down
4 changes: 2 additions & 2 deletions Sources/SourceKitLSP/Swift/OpenInterface.swift
Original file line number Diff line number Diff line change
Expand Up @@ -82,7 +82,7 @@ extension SwiftLanguageServer {
skreq[keys.compilerargs] = compileCommand.compilerArgs
}

let dict = try await self.sourcekitd.send(skreq)
let dict = try await self.sourcekitd.send(skreq, fileContents: nil)
return InterfaceInfo(contents: dict[keys.sourcetext] ?? "")
}

Expand All @@ -103,7 +103,7 @@ extension SwiftLanguageServer {
skreq[keys.sourcefile] = uri.pseudoPath
skreq[keys.usr] = symbol

let dict = try await self.sourcekitd.send(skreq)
let dict = try await self.sourcekitd.send(skreq, fileContents: snapshot.text)
if let offset: Int = dict[keys.offset],
let position = snapshot.positionOf(utf8Offset: offset)
{
Expand Down
2 changes: 1 addition & 1 deletion Sources/SourceKitLSP/Swift/SemanticRefactoring.swift
Original file line number Diff line number Diff line change
Expand Up @@ -155,7 +155,7 @@ extension SwiftLanguageServer {
skreq[keys.compilerargs] = compileCommand.compilerArgs
}

let dict = try await self.sourcekitd.send(skreq)
let dict = try await self.sourcekitd.send(skreq, fileContents: snapshot.text)
guard let refactor = SemanticRefactoring(refactorCommand.title, dict, snapshot, self.keys) else {
throw SemanticRefactoringError.noEditsNeeded(uri)
}
Expand Down
2 changes: 1 addition & 1 deletion Sources/SourceKitLSP/Swift/SemanticTokens.swift
Original file line number Diff line number Diff line change
Expand Up @@ -31,7 +31,7 @@ extension SwiftLanguageServer {
// FIXME: SourceKit should probably cache this for us.
skreq[keys.compilerargs] = buildSettings.compilerArgs

let dict = try await sourcekitd.send(skreq)
let dict = try await sourcekitd.send(skreq, fileContents: snapshot.text)

guard let skTokens: SKDResponseArray = dict[keys.semantic_tokens] else {
return nil
Expand Down
16 changes: 8 additions & 8 deletions Sources/SourceKitLSP/Swift/SwiftLanguageServer.swift
Original file line number Diff line number Diff line change
Expand Up @@ -262,7 +262,7 @@ extension SwiftLanguageServer {
public func _crash() async {
let req = SKDRequestDictionary(sourcekitd: sourcekitd)
req[sourcekitd.keys.request] = sourcekitd.requests.crash_exit
_ = try? await sourcekitd.send(req)
_ = try? await sourcekitd.send(req, fileContents: nil)
}

// MARK: - Build System Integration
Expand All @@ -276,7 +276,7 @@ extension SwiftLanguageServer {
let closeReq = SKDRequestDictionary(sourcekitd: self.sourcekitd)
closeReq[keys.request] = self.requests.editor_close
closeReq[keys.name] = path
_ = try? await self.sourcekitd.send(closeReq)
_ = try? await self.sourcekitd.send(closeReq, fileContents: nil)

let openReq = SKDRequestDictionary(sourcekitd: self.sourcekitd)
openReq[keys.request] = self.requests.editor_open
Expand All @@ -286,7 +286,7 @@ extension SwiftLanguageServer {
openReq[keys.compilerargs] = compileCmd.compilerArgs
}

_ = try? await self.sourcekitd.send(openReq)
_ = try? await self.sourcekitd.send(openReq, fileContents: snapshot.text)

publishDiagnosticsIfNeeded(for: snapshot.uri)
}
Expand Down Expand Up @@ -336,7 +336,7 @@ extension SwiftLanguageServer {
req[keys.compilerargs] = compilerArgs
}

_ = try? await self.sourcekitd.send(req)
_ = try? await self.sourcekitd.send(req, fileContents: snapshot.text)
publishDiagnosticsIfNeeded(for: note.textDocument.uri)
}

Expand All @@ -354,7 +354,7 @@ extension SwiftLanguageServer {
req[keys.request] = self.requests.editor_close
req[keys.name] = uri.pseudoPath

_ = try? await self.sourcekitd.send(req)
_ = try? await self.sourcekitd.send(req, fileContents: nil)
}

/// Cancels any in-flight tasks to send a `PublishedDiagnosticsNotification` after edits.
Expand Down Expand Up @@ -464,7 +464,7 @@ extension SwiftLanguageServer {
req[keys.length] = edit.length
req[keys.sourcetext] = edit.replacement
do {
_ = try await self.sourcekitd.send(req)
_ = try await self.sourcekitd.send(req, fileContents: nil)
} catch {
fatalError("failed to apply edit")
}
Expand Down Expand Up @@ -639,7 +639,7 @@ extension SwiftLanguageServer {
skreq[keys.compilerargs] = compileCommand.compilerArgs
}

let dict = try await self.sourcekitd.send(skreq)
let dict = try await self.sourcekitd.send(skreq, fileContents: snapshot.text)

guard let results: SKDResponseArray = dict[self.keys.results] else {
return []
Expand Down Expand Up @@ -1090,7 +1090,7 @@ extension SwiftLanguageServer {
// FIXME: SourceKit should probably cache this for us.
skreq[keys.compilerargs] = buildSettings.compilerArgs

let dict = try await self.sourcekitd.send(skreq)
let dict = try await self.sourcekitd.send(skreq, fileContents: snapshot.text)

try Task.checkCancellation()
guard (try? documentManager.latestSnapshot(req.textDocument.uri).id) == snapshot.id else {
Expand Down
2 changes: 1 addition & 1 deletion Sources/SourceKitLSP/Swift/VariableTypeInfo.swift
Original file line number Diff line number Diff line change
Expand Up @@ -104,7 +104,7 @@ extension SwiftLanguageServer {
skreq[keys.compilerargs] = compileCommand.compilerArgs
}

let dict = try await self.sourcekitd.send(skreq)
let dict = try await self.sourcekitd.send(skreq, fileContents: snapshot.text)
guard let skVariableTypeInfos: SKDResponseArray = dict[keys.variable_type_list] else {
return []
}
Expand Down
4 changes: 2 additions & 2 deletions Tests/SourceKitDTests/SourceKitDTests.swift
Original file line number Diff line number Diff line change
Expand Up @@ -88,14 +88,14 @@ final class SourceKitDTests: XCTestCase {
args.append(path)
req[keys.compilerargs] = args

_ = try await sourcekitd.send(req)
_ = try await sourcekitd.send(req, fileContents: nil)

try await fulfillmentOfOrThrow([expectation1, expectation2])

let close = SKDRequestDictionary(sourcekitd: sourcekitd)
close[keys.request] = sourcekitd.requests.editor_close
close[keys.name] = path
_ = try await sourcekitd.send(close)
_ = try await sourcekitd.send(close, fileContents: nil)
}
}

Expand Down