search

scalameta / metals

Scala language server with rich IDE features 🚀
https://scalameta.org/metals/
Apache License 2.0
2.1k stars 334 forks source link

Test output not parsed (RuntimeException "searching for `#` failed") #5101

Closed elm- closed 11 months ago

elm- commented 1 year ago

Running any test command in the project does not update the test explorer view.

By using run test or run all tests in project, the tests are correctly executed (as seen in the debug console output), but the test results are not shown in the testing UI or lenses (I tried switching the setting, same result).

I tried already cleaning everything and resetting the project, the problem persists and is happening across any project I try.

The following exception is shown in the Metals output console:

2023.03.29 14:56:33 ERROR searching for `#` failed
java.lang.RuntimeException: invalid symbol format
#
^
    at scala.sys.package$.error(package.scala:27)
    at scala.meta.internal.semanticdb.Scala$DescriptorParser.fail(Scala.scala:202)
    at scala.meta.internal.semanticdb.Scala$DescriptorParser.readChar(Scala.scala:215)
    at scala.meta.internal.semanticdb.Scala$DescriptorParser.parseValue(Scala.scala:233)
    at scala.meta.internal.semanticdb.Scala$DescriptorParser.parseDescriptor(Scala.scala:258)
    at scala.meta.internal.semanticdb.Scala$DescriptorParser.entryPoint(Scala.scala:281)
    at scala.meta.internal.semanticdb.Scala$DescriptorParser$.apply(Scala.scala:289)
    at scala.meta.internal.semanticdb.Scala$ScalaSymbolOps$.owner$extension(Scala.scala:103)
    at scala.meta.internal.mtags.Symbol.toplevel(Symbol.scala:56)
    at scala.meta.internal.mtags.SymbolIndexBucket.query0(SymbolIndexBucket.scala:178)
    at scala.meta.internal.mtags.SymbolIndexBucket.query(SymbolIndexBucket.scala:158)
    at scala.meta.internal.mtags.OnDemandSymbolIndex.$anonfun$findSymbolDefinition$1(OnDemandSymbolIndex.scala:139)
    at scala.collection.immutable.List.flatMap(List.scala:293)
    at scala.meta.internal.mtags.OnDemandSymbolIndex.findSymbolDefinition(OnDemandSymbolIndex.scala:139)
    at scala.meta.internal.mtags.OnDemandSymbolIndex.definitions(OnDemandSymbolIndex.scala:56)
    at scala.meta.internal.metals.DestinationProvider.definition(DefinitionProvider.scala:463)
    at scala.meta.internal.metals.DestinationProvider.fromSymbol(DefinitionProvider.scala:501)
    at scala.meta.internal.metals.DestinationProvider.fromSymbol(DefinitionProvider.scala:542)
    at scala.meta.internal.metals.DefinitionProvider.fromSymbol(DefinitionProvider.scala:197)
    at scala.meta.internal.metals.StacktraceAnalyzer.findLocationForSymbol$1(StacktraceAnalyzer.scala:67)
    at scala.meta.internal.metals.StacktraceAnalyzer.$anonfun$fileLocationFromLine$2(StacktraceAnalyzer.scala:72)
    at scala.PartialFunction$Unlifted.applyOrElse(PartialFunction.scala:347)
    at scala.collection.IterableOnceOps.collectFirst(IterableOnce.scala:1116)
    at scala.collection.IterableOnceOps.collectFirst$(IterableOnce.scala:1108)
    at scala.collection.AbstractIterable.collectFirst(Iterable.scala:933)
    at scala.meta.internal.metals.StacktraceAnalyzer.$anonfun$fileLocationFromLine$1(StacktraceAnalyzer.scala:72)
    at scala.Option.flatMap(Option.scala:283)
    at scala.meta.internal.metals.StacktraceAnalyzer.fileLocationFromLine(StacktraceAnalyzer.scala:70)
    at scala.meta.internal.metals.debug.DebugProxy.$anonfun$handleServerMessage$1(DebugProxy.scala:207)
    at scala.meta.internal.metals.debug.DebugProxy.$anonfun$handleServerMessage$1$adapted(DebugProxy.scala:176)
    at scala.meta.internal.metals.debug.ServerAdapter.$anonfun$onReceived$1(ServerAdapter.scala:25)
    at scala.meta.internal.metals.debug.MessageIdAdapter.$anonfun$listen$1(MessageIdAdapter.scala:57)
    at org.eclipse.lsp4j.jsonrpc.json.StreamMessageProducer.handleMessage(StreamMessageProducer.java:194)
    at org.eclipse.lsp4j.jsonrpc.json.StreamMessageProducer.listen(StreamMessageProducer.java:94)
    at scala.meta.internal.metals.debug.SocketEndpoint.listen(SocketEndpoint.scala:26)
    at scala.meta.internal.metals.debug.MessageIdAdapter.listen(MessageIdAdapter.scala:47)
    at scala.meta.internal.metals.debug.ServerAdapter.onReceived(ServerAdapter.scala:18)
    at scala.meta.internal.metals.debug.DebugProxy.$anonfun$listenToServer$1(DebugProxy.scala:72)
    at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.scala:18)
    at scala.concurrent.Future$.$anonfun$apply$1(Future.scala:678)
    at scala.concurrent.impl.Promise$Transformation.run(Promise.scala:467)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
    at java.lang.Thread.run(Thread.java:833)

2023.03.29 14:56:34 INFO  Canceling debug proxy for [*** replaced ** SomethingTest]

Expected behaviour:

Testing results are parsed and visualized.

Operating system: Mac OS X

Java version: 17.0.6

Editor/extension: Visual Studio Code v1.76.2

Metals version: 0.11.11

Extra context or search terms:

Workspace information:

kpodsiad commented 1 year ago

(techincal paragraph) Test Explorer might not be updated because it relies on events which are being sent through Debug Adapter Protocol between debugee (vs code) and debugger. So I guess this exception could be the reason for that.

Could you follow https://scalameta.org/metals/docs/contributors/getting-started#json-rpc-trace and create trace files - dap-server.trace.json and dap-client.trace.json in .metals? Then after running/debugging something try to search for "event": "testResult" in those files. This will tell us if this exception is related to the problme or not.

elm- commented 1 year ago

Thanks, here the relevant event, the rest of the trace seems to correctly pass the additional output of the test run as events as well. The only thing which looks "weird" to me in the event is that all test have the same timings instead of individual timings, not sure if that is normal or not.

server

[Trace][04:29:22 PM] Received notification:
{
  "type": "event",
  "seq": 40,
  "event": "testResult",
  "body": {
    "category": "testResult",
    "data": {
      "suiteName": "com.cupenya.sqlstreamsync.sql.RowEventProcessorTest",
      "duration": 1774,
      "tests": [
        {
          "kind": "passed",
          "testName": "RowEventProcessor.extractRow should::return a list of extracted values from ResultSet",
          "duration": 1774
        },
        {
          "kind": "passed",
          "testName": "RowEventProcessor.extractRow should::return None for null values",
          "duration": 1774
        },
        {
          "kind": "passed",
          "testName": "RowEventProcessor utils should::format date",
          "duration": 1774
        },
        {
          "kind": "passed",
          "testName": "RowEventProcessor utils should::parse date",
          "duration": 1774
        },
        {
          "kind": "passed",
          "testName": "RowEventProcessor utils should::parse date for epoch",
          "duration": 1774
        }
      ]
    },
    "type": "testResult"
  }
}

client:


[Trace][04:29:22 PM] Sent notification:
{
  "type": "event",
  "seq": 40,
  "event": "testResult",
  "body": {
    "category": "testResult",
    "data": {
      "suiteName": "com.cupenya.sqlstreamsync.sql.RowEventProcessorTest",
      "duration": 1774,
      "tests": [
        {
          "kind": "passed",
          "testName": "RowEventProcessor.extractRow should::return a list of extracted values from ResultSet",
          "duration": 1774
        },
        {
          "kind": "passed",
          "testName": "RowEventProcessor.extractRow should::return None for null values",
          "duration": 1774
        },
        {
          "kind": "passed",
          "testName": "RowEventProcessor utils should::format date",
          "duration": 1774
        },
        {
          "kind": "passed",
          "testName": "RowEventProcessor utils should::parse date",
          "duration": 1774
        },
        {
          "kind": "passed",
          "testName": "RowEventProcessor utils should::parse date for epoch",
          "duration": 1774
        }
      ]
    },
    "type": "testResult"
  }
}```
kpodsiad commented 1 year ago

@elm- duration is incorrect but it's fixed already https://github.com/scalacenter/scala-debug-adapter/pull/366 so after some internal guts are updated, duration should be correct.

I tried already cleaning everything and resetting the project, the problem persists and is happening across any project I try.

This might indicate that problem is somewhere else, but on the other hand, there are events in trace files and metals extension should capture those events and interpret them. Could you try to provide some repository with reproduction? Also, what test framework do you use?

elm- commented 1 year ago

I'll see if I can reproduce this over the weekend in a simpler project and I'll also double check if this works potentially in a devcontainer, just to make sure nothing is locally broken.

github-actions[bot] commented 11 months ago

This issue was closed because no new information was added for the last 30 days. If you have any relevant information, feel free to add it and reopen the issue.