luke
/
sbt
mirror of https://github.com/sbt/sbt.git
1
0
Fork 0
Code Issues Packages Projects Releases Wiki Activity

Improve BSP processing logs 

The processing log is sent when a command issued by a request is being
processed, if the request has not yet been responded. In particular,
the processing log of sbtReportResult is filtered out if the client has
already received a response.

The processing log severity is the lowest so that it can be ignored by
the BSP client.
This commit is contained in:
Adrien Piquerez 2021-03-09 10:18:12 +01:00
parent ff6cbf2e1f
commit 93afa7e892
4 changed files with 63 additions and 58 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

4
main/src/main/scala/sbt/MainLoop.scala
View File

@ -205,8 +205,10 @@ object MainLoop {
def processCommand(exec: Exec, state: State): State = {
val channelName = exec.source map (_.channelName)
val exchange = StandardMain.exchange
exchange notifyStatus
exchange.setState(state)
exchange.notifyStatus(
ExecStatusEvent("Processing", channelName, exec.execId, Vector())
)
try {
def process(): State = {
val progressState = state.get(sbt.Keys.currentTaskProgress) match {

2
main/src/main/scala/sbt/internal/server/BuildServerProtocol.scala
View File

@ -256,7 +256,7 @@ object BuildServerProtocol {
val _ = callback.appendExec(Keys.bspWorkspaceBuildTargets.key.toString, Some(r.id))
case r: JsonRpcRequestMessage if r.method == "workspace/reload" =>
val _ = callback.appendExec(s"$bspReload ${r.id}", None)
val _ = callback.appendExec(s"$bspReload ${r.id}", Some(r.id))
case r: JsonRpcRequestMessage if r.method == "build/shutdown" =>
callback.jsonRpcRespond(JNull, Some(r.id))

69
main/src/main/scala/sbt/internal/server/NetworkChannel.scala
View File

@ -255,23 +255,25 @@ final class NetworkChannel(
err: JsonRpcResponseError,
execId: Option[String]
): Unit = this.synchronized {
def respond(id: String) = {
pendingRequests -= id
jsonRpcRespondError(id, err)
getPendingRequest(execId) match {
case Some(request) =>
pendingRequests -= request.id
jsonRpcRespondError(request.id, err)
case _ => logMessage("error", s"Error ${err.code}: ${err.message}")
}
def error(): Unit = logMessage("error", s"Error ${err.code}: ${err.message}")
execId match {
case Some(id) if pendingRequests.contains(id) => respond(id)
}
private[sbt] def getPendingRequest(execId: Option[String]): Option[JsonRpcRequestMessage] = {
execId.flatMap {
// This handles multi commands from the network that were remapped to a different
// exec id for reporting purposes.
case Some(id) if id.startsWith(BasicCommandStrings.networkExecPrefix) =>
case id if id.startsWith(BasicCommandStrings.networkExecPrefix) =>
StandardMain.exchange.withState { s =>
s.get(BasicCommands.execMap).flatMap(_.collectFirst { case (k, `id`) => k }) match {
case Some(id) if pendingRequests.contains(id) => respond(id)
case _ => error()
}
s.get(BasicCommands.execMap)
.flatMap(_.collectFirst { case (k, `id`) => k })
.flatMap(pendingRequests.get)
}
case _ => error()
case id => pendingRequests.get(id)
}
}
@ -287,27 +289,14 @@ final class NetworkChannel(
event: A,
execId: Option[String]
): Unit = this.synchronized {
def error(): Unit = {
val msg =
s"unmatched json response for requestId $execId: ${CompactPrinter(Converter.toJsonUnsafe(event))}"
log.debug(msg)
}
def respond(id: String): Unit = {
pendingRequests -= id
jsonRpcRespond(event, id)
}
execId match {
case Some(id) if pendingRequests.contains(id) => respond(id)
// This handles multi commands from the network that were remapped to a different
// exec id for reporting purposes.
case Some(id) if id.startsWith(BasicCommandStrings.networkExecPrefix) =>
StandardMain.exchange.withState { s =>
s.get(BasicCommands.execMap).flatMap(_.collectFirst { case (k, `id`) => k }) match {
case Some(id) if pendingRequests.contains(id) => respond(id)
case _ => error()
}
}
case _ => error()
getPendingRequest(execId) match {
case Some(request) =>
pendingRequests -= request.id
jsonRpcRespond(event, request.id)
case _ =>
val msg =
s"unmatched json response for requestId $execId: ${CompactPrinter(Converter.toJsonUnsafe(event))}"
log.debug(msg)
}
}
@ -323,9 +312,17 @@ final class NetworkChannel(
def notifyEvent(event: EventMessage): Unit = {
event match {
case entry: LogEvent => logMessage(entry.level, entry.message)
case entry: ExecStatusEvent => logMessage("debug", entry.status)
case _ => ()
case entry: LogEvent => logMessage(entry.level, entry.message)
case entry: ExecStatusEvent =>
getPendingRequest(entry.execId) match {
case Some(request) =>
logMessage("debug", s"${entry.status} ${request.method}")
case None =>
log.debug(
s"unmatched ${entry.status} event for requestId ${entry.execId}: ${entry.message}"
)
}
case _ => ()
}
}

46
server-test/src/test/scala/testpkg/BuildServerTest.scala
View File

@ -16,8 +16,7 @@ object BuildServerTest extends AbstractServerTest {
test("build/initialize") { _ =>
initializeRequest()
assert(svr.waitForString(10.seconds) { s =>
println(s)
(s contains """"id":"10"""")
s contains """"id":"10""""
})
}
@ -25,11 +24,13 @@ object BuildServerTest extends AbstractServerTest {
svr.sendJsonRpc(
"""{ "jsonrpc": "2.0", "id": "11", "method": "workspace/buildTargets", "params": {} }"""
)
assert(svr.waitForString(10.seconds) { s =>
println(s)
(s contains """"id":"11"""") &&
(s contains """"displayName":"util"""")
})
assert(processing("workspace/buildTargets"))
assert {
svr.waitForString(10.seconds) { s =>
(s contains """"id":"11"""") &&
(s contains """"displayName":"util"""")
}
}
}
test("buildTarget/sources") { _ =>
@ -39,8 +40,8 @@ object BuildServerTest extends AbstractServerTest {
| "targets": [{ "uri": "$x" }]
|} }""".stripMargin
)
assert(processing("buildTarget/sources"))
assert(svr.waitForString(10.seconds) { s =>
println(s)
(s contains """"id":"12"""") &&
(s contains "util/src/main/scala")
})
@ -53,8 +54,8 @@ object BuildServerTest extends AbstractServerTest {
| "targets": [{ "uri": "$x" }]
|} }""".stripMargin
)
assert(processing("buildTarget/compile"))
assert(svr.waitForString(10.seconds) { s =>
println(s)
(s contains """"id":"13"""") &&
(s contains """"statusCode":1""")
})
@ -67,8 +68,8 @@ object BuildServerTest extends AbstractServerTest {
| "targets": [{ "uri": "$x" }]
|} }""".stripMargin
)
assert(processing("buildTarget/scalacOptions"))
assert(svr.waitForString(10.seconds) { s =>
println(s)
(s contains """"id":"14"""") &&
(s contains "scala-library-2.13.1.jar")
})
@ -78,8 +79,8 @@ object BuildServerTest extends AbstractServerTest {
svr.sendJsonRpc(
"""{ "jsonrpc": "2.0", "id": "15", "method": "workspace/reload"}"""
)
assert(processing("workspace/reload"))
assert(svr.waitForString(10.seconds) { s =>
println(s)
(s contains """"id":"15"""") &&
(s contains """"result":null""")
})
@ -92,8 +93,8 @@ object BuildServerTest extends AbstractServerTest {
| "targets": [{ "uri": "$x" }]
|} }""".stripMargin
)
assert(processing("buildTarget/scalaMainClasses"))
assert(svr.waitForString(30.seconds) { s =>
println(s)
(s contains """"id":"16"""") &&
(s contains """"class":"main.Main"""")
})
@ -108,13 +109,12 @@ object BuildServerTest extends AbstractServerTest {
| "data": { "class": "main.Main" }
|} }""".stripMargin
)
assert(processing("buildTarget/run"))
assert(svr.waitForString(10.seconds) { s =>
println(s)
(s contains "build/logMessage") &&
(s contains """"message":"Hello World!"""")
})
assert(svr.waitForString(10.seconds) { s =>
println(s)
(s contains """"id":"17"""") &&
(s contains """"statusCode":1""")
})
@ -127,8 +127,8 @@ object BuildServerTest extends AbstractServerTest {
| "targets": [{ "uri": "$x" }]
|} }""".stripMargin
)
assert(processing("buildTarget/scalaTestClasses"))
assert(svr.waitForString(10.seconds) { s =>
println(s)
(s contains """"id":"18"""") &&
(s contains """"tests.FailingTest"""") &&
(s contains """"tests.PassingTest"""")
@ -142,8 +142,8 @@ object BuildServerTest extends AbstractServerTest {
| "targets": [{ "uri": "$x" }]
|} }""".stripMargin
)
assert(processing("buildTarget/test"))
assert(svr.waitForString(10.seconds) { s =>
println(s)
(s contains """"id":"19"""") &&
(s contains """"statusCode":2""")
})
@ -165,8 +165,8 @@ object BuildServerTest extends AbstractServerTest {
| }
|} }""".stripMargin
)
assert(processing("buildTarget/test"))
assert(svr.waitForString(10.seconds) { s =>
println(s)
(s contains """"id":"20"""") &&
(s contains """"statusCode":1""")
})
@ -180,7 +180,6 @@ object BuildServerTest extends AbstractServerTest {
|} }""".stripMargin
)
assert(svr.waitForString(10.seconds) { s =>
println(s)
(s contains s""""buildTarget":{"uri":"$x"}""") &&
(s contains """"severity":1""") &&
(s contains """"reset":true""")
@ -195,14 +194,13 @@ object BuildServerTest extends AbstractServerTest {
|} }""".stripMargin
)
assert(svr.waitForString(10.seconds) { s =>
println(s)
(s contains s""""buildTarget":{"uri":"$x"}""") &&
(s contains """"severity":2""") &&
(s contains """"reset":true""")
})
}
def initializeRequest(): Unit = {
private def initializeRequest(): Unit = {
svr.sendJsonRpc(
"""{ "jsonrpc": "2.0", "id": "10", "method": "build/initialize",
| "params": {
@ -215,4 +213,12 @@ object BuildServerTest extends AbstractServerTest {
|}""".stripMargin
)
}
private def processing(method: String, debug: Boolean = false): Boolean = {
svr.waitForString(10.seconds) { msg =>
if (debug) println(msg)
msg.contains("build/logMessage") &&
msg.contains(s""""message":"Processing $method"""")
}
}
}