From f9d2964e83279097f5b1f403e60cb0c9c74d2896 Mon Sep 17 00:00:00 2001 From: Dmitry Bushev Date: Tue, 24 May 2022 16:01:26 +0300 Subject: [PATCH] Update profiling CLI arguments (#3461) --- CHANGELOG.md | 1 + build.sbt | 7 +- .../boot/LanguageServerComponent.scala | 35 +++++- .../boot/LanguageServerConfig.scala | 10 +- .../enso/languageserver/boot/MainModule.scala | 28 +++-- .../languageserver/boot/ProfilingConfig.scala | 18 ++++ .../org/enso/languageserver/data/Config.scala | 6 +- .../runtime/ApiEventsMonitor.scala | 18 ++-- .../runtime/ContextRegistry.scala | 18 +--- .../resource/RepoInitializationSpec.scala | 5 +- .../filemanager/ContentRootManagerSpec.scala | 5 +- .../runtime/ContextEventsListenerSpec.scala | 5 +- .../search/SuggestionsHandlerSpec.scala | 4 +- .../binary/BaseBinaryServerTest.scala | 4 +- .../websocket/json/BaseServerTest.scala | 8 +- .../websocket/json/FileManagerTest.scala | 20 ++-- .../launcher/cli/LauncherApplication.scala | 3 +- .../org/enso/runner/LanguageServerApp.scala | 32 +++++- .../src/main/scala/org/enso/runner/Main.scala | 63 ++++++++--- .../org/enso/jsonrpc/JsonRpcServer.scala | 10 +- .../JavaLoggingLogHandler.scala | 23 +--- .../org/enso/loggingservice/LogLevel.scala | 12 +++ .../LoggingServiceSetupHelper.scala | 22 ++-- .../printers/FileOutputPrinter.scala | 2 +- .../printers/FileXmlPrinter.scala | 61 +++++++++++ ...empFileSampler.scala => FileSampler.scala} | 30 +----- .../org/enso/profiling/MethodsSampler.scala | 4 +- .../org/enso/profiling/NoopSampler.scala | 4 +- .../org/enso/projectmanager/boot/Cli.scala | 45 ++++++-- .../projectmanager/boot/ProjectManager.scala | 102 ++++++++++++++++-- .../boot/ProjectManagerOptions.scala | 17 +++ .../projectmanager/boot/configuration.scala | 9 +- .../ExecutorWithUnlimitedPool.scala | 17 ++- .../LanguageServerController.scala | 4 +- .../LanguageServerDescriptor.scala | 14 ++- .../enso/projectmanager/BaseServerSpec.scala | 8 +- 36 files changed, 499 insertions(+), 175 deletions(-) create mode 100644 engine/language-server/src/main/scala/org/enso/languageserver/boot/ProfilingConfig.scala create mode 100644 lib/scala/logging-service/src/main/scala/org/enso/loggingservice/printers/FileXmlPrinter.scala rename lib/scala/profiling-utils/src/main/scala/org/enso/profiling/{TempFileSampler.scala => FileSampler.scala} (60%) create mode 100644 lib/scala/project-manager/src/main/scala/org/enso/projectmanager/boot/ProjectManagerOptions.scala diff --git a/CHANGELOG.md b/CHANGELOG.md index 0abe9b8227..9a3e4ddc82 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -235,6 +235,7 @@ [3444]: https://github.com/enso-org/enso/pull/3444 [3453]: https://github.com/enso-org/enso/pull/3453 [3454]: https://github.com/enso-org/enso/pull/3454 +[3461]: https://github.com/enso-org/enso/pull/3461 [3465]: https://github.com/enso-org/enso/pull/3465 # Enso 2.0.0-alpha.18 (2021-10-12) diff --git a/build.sbt b/build.sbt index 003a30e4c4..1bb9827880 100644 --- a/build.sbt +++ b/build.sbt @@ -905,9 +905,10 @@ lazy val `json-rpc-server` = project libraryDependencies ++= akka ++ akkaTest, libraryDependencies ++= circe, libraryDependencies ++= Seq( - "io.circe" %% "circe-literal" % circeVersion, - akkaTestkit % Test, - "org.scalatest" %% "scalatest" % scalatestVersion % Test + "io.circe" %% "circe-literal" % circeVersion, + "com.typesafe.scala-logging" %% "scala-logging" % scalaLoggingVersion, + akkaTestkit % Test, + "org.scalatest" %% "scalatest" % scalatestVersion % Test ) ) diff --git a/engine/language-server/src/main/scala/org/enso/languageserver/boot/LanguageServerComponent.scala b/engine/language-server/src/main/scala/org/enso/languageserver/boot/LanguageServerComponent.scala index 2f32d27b5a..1657003e2a 100644 --- a/engine/language-server/src/main/scala/org/enso/languageserver/boot/LanguageServerComponent.scala +++ b/engine/language-server/src/main/scala/org/enso/languageserver/boot/LanguageServerComponent.scala @@ -15,9 +15,10 @@ import org.enso.languageserver.runtime.RuntimeKiller.{ ShutDownRuntime } import org.enso.loggingservice.LogLevel +import org.enso.profiling.{FileSampler, MethodsSampler, NoopSampler} import scala.concurrent.duration._ -import scala.concurrent.{Await, Future} +import scala.concurrent.{Await, ExecutionContextExecutor, Future} /** A lifecycle component used to start and stop a Language Server. * @@ -31,11 +32,14 @@ class LanguageServerComponent(config: LanguageServerConfig, logLevel: LogLevel) @volatile private var maybeServerCtx: Option[ServerContext] = None - implicit private val ec = config.computeExecutionContext + implicit private val ec: ExecutionContextExecutor = + config.computeExecutionContext /** @inheritdoc */ override def start(): Future[ComponentStarted.type] = { logger.info("Starting Language Server...") + val sampler = startSampling(config) + logger.debug(s"Started ${sampler.getClass.getName}.") val module = new MainModule(config, logLevel) val bindJsonServer = for { @@ -51,7 +55,8 @@ class LanguageServerComponent(config: LanguageServerConfig, logLevel: LogLevel) jsonBinding <- bindJsonServer binaryBinding <- bindBinaryServer _ <- Future { - maybeServerCtx = Some(ServerContext(module, jsonBinding, binaryBinding)) + maybeServerCtx = + Some(ServerContext(sampler, module, jsonBinding, binaryBinding)) } _ <- Future { logger.info( @@ -62,14 +67,29 @@ class LanguageServerComponent(config: LanguageServerConfig, logLevel: LogLevel) } yield ComponentStarted } + /** Start the application sampling. */ + private def startSampling(config: LanguageServerConfig): MethodsSampler = { + val sampler = config.profilingConfig.profilingPath match { + case Some(path) => + new FileSampler(path.toFile) + case None => + NoopSampler() + } + sampler.start() + config.profilingConfig.profilingTime.foreach(sampler.stop(_)) + + sampler + } + /** @inheritdoc */ override def stop(): Future[ComponentStopped.type] = maybeServerCtx match { case None => - Future.failed(new Exception("Server isn't running")) + Future.successful(ComponentStopped) case Some(serverContext) => for { + _ <- stopSampling(serverContext) _ <- terminateTruffle(serverContext) _ <- terminateAkka(serverContext) _ <- releaseResources(serverContext) @@ -77,6 +97,9 @@ class LanguageServerComponent(config: LanguageServerConfig, logLevel: LogLevel) } yield ComponentStopped } + private def stopSampling(serverContext: ServerContext): Future[Unit] = + Future(serverContext.sampler.stop()).recover(logError) + private def releaseResources(serverContext: ServerContext): Future[Unit] = for { _ <- Future(serverContext.mainModule.close()).recover(logError) @@ -101,7 +124,7 @@ class LanguageServerComponent(config: LanguageServerConfig, logLevel: LogLevel) } private def terminateTruffle(serverContext: ServerContext): Future[Unit] = { - implicit val askTimeout = Timeout(12.seconds) + implicit val askTimeout: Timeout = Timeout(12.seconds) val killFiber = (serverContext.mainModule.runtimeKiller ? ShutDownRuntime) .mapTo[RuntimeShutdownResult] @@ -129,11 +152,13 @@ object LanguageServerComponent { /** A running server context. * + * @param sampler a sampler gathering the application performance statistics * @param mainModule a main module containing all components of the server * @param jsonBinding a http binding for rpc protocol * @param binaryBinding a http binding for data protocol */ case class ServerContext( + sampler: MethodsSampler, mainModule: MainModule, jsonBinding: Http.ServerBinding, binaryBinding: Http.ServerBinding diff --git a/engine/language-server/src/main/scala/org/enso/languageserver/boot/LanguageServerConfig.scala b/engine/language-server/src/main/scala/org/enso/languageserver/boot/LanguageServerConfig.scala index 3c9afe2b0d..9fca74591f 100644 --- a/engine/language-server/src/main/scala/org/enso/languageserver/boot/LanguageServerConfig.scala +++ b/engine/language-server/src/main/scala/org/enso/languageserver/boot/LanguageServerConfig.scala @@ -2,7 +2,7 @@ package org.enso.languageserver.boot import java.util.UUID -import scala.concurrent.ExecutionContext +import scala.concurrent.{ExecutionContext, ExecutionContextExecutor} /** The config of the running Language Server instance. * @@ -11,7 +11,7 @@ import scala.concurrent.ExecutionContext * @param dataPort a data port that the server listen to * @param contentRootUuid an id of content root * @param contentRootPath a path to the content root - * @param isProfilingEnabled is the application profiling enabled + * @param profilingConfig an application profiling configuration */ case class LanguageServerConfig( interface: String, @@ -19,7 +19,7 @@ case class LanguageServerConfig( dataPort: Int, contentRootUuid: UUID, contentRootPath: String, - isProfilingEnabled: Boolean, - name: String = "language-server", - computeExecutionContext: ExecutionContext = ExecutionContext.global + profilingConfig: ProfilingConfig, + name: String = "language-server", + computeExecutionContext: ExecutionContextExecutor = ExecutionContext.global ) diff --git a/engine/language-server/src/main/scala/org/enso/languageserver/boot/MainModule.scala b/engine/language-server/src/main/scala/org/enso/languageserver/boot/MainModule.scala index 3fa4a0fd8d..8742f8ee59 100644 --- a/engine/language-server/src/main/scala/org/enso/languageserver/boot/MainModule.scala +++ b/engine/language-server/src/main/scala/org/enso/languageserver/boot/MainModule.scala @@ -44,7 +44,6 @@ import org.enso.lockmanager.server.LockManagerService import org.enso.logger.masking.Masking import org.enso.loggingservice.{JavaLoggingLogHandler, LogLevel} import org.enso.polyglot.{RuntimeOptions, RuntimeServerInfo} -import org.enso.profiling.{NoopSampler, TempFileSampler} import org.enso.searcher.sql.{SqlDatabase, SqlSuggestionsRepo, SqlVersionsRepo} import org.enso.text.{ContentBasedVersioning, Sha3_224VersionCalculator} import org.graalvm.polyglot.Context @@ -56,6 +55,7 @@ import java.net.URI import java.time.Clock import scala.concurrent.duration._ +import scala.util.{Failure, Success} /** A main module containing all components of the server. * @@ -83,7 +83,8 @@ class MainModule(serverConfig: LanguageServerConfig, logLevel: LogLevel) { FileManagerConfig(timeout = 3.seconds), PathWatcherConfig(), ExecutionContextConfig(), - directoriesConfig + directoriesConfig, + serverConfig.profilingConfig ) log.trace("Created Language Server config [{}].", languageServerConfig) @@ -148,8 +149,20 @@ class MainModule(serverConfig: LanguageServerConfig, logLevel: LogLevel) { ) val runtimeEventsMonitor = - if (logLevel == LogLevel.Trace) ApiEventsMonitor() - else new NoopEventsMonitor + languageServerConfig.profiling.runtimeEventsLogPath match { + case Some(path) => + ApiEventsMonitor(path) match { + case Success(monitor) => + monitor + case Failure(exception) => + log.error( + s"Failed to create runtime events monitor for $path ($exception)." + ) + new NoopEventsMonitor + } + case None => + new NoopEventsMonitor + } log.trace( s"Started runtime events monitor ${runtimeEventsMonitor.getClass.getName}." ) @@ -228,12 +241,7 @@ class MainModule(serverConfig: LanguageServerConfig, logLevel: LogLevel) { languageServerConfig, RuntimeFailureMapper(contentRootManagerWrapper), runtimeConnector, - sessionRouter, - if (serverConfig.isProfilingEnabled) { - val s = TempFileSampler("context-registry") - JavaLoggingLogHandler.registerLogFile(s.getSiblingFile(".log")) - s - } else NoopSampler() + sessionRouter ), "context-registry" ) diff --git a/engine/language-server/src/main/scala/org/enso/languageserver/boot/ProfilingConfig.scala b/engine/language-server/src/main/scala/org/enso/languageserver/boot/ProfilingConfig.scala new file mode 100644 index 0000000000..38ba6527ea --- /dev/null +++ b/engine/language-server/src/main/scala/org/enso/languageserver/boot/ProfilingConfig.scala @@ -0,0 +1,18 @@ +package org.enso.languageserver.boot + +import java.nio.file.Path + +import scala.concurrent.duration.FiniteDuration + +/** Application profiling configuration. + * + * @param runtimeEventsLogPath the path to the runtime events log file + * @param profilingPath the path to the profiling output file + * @param profilingTime limit the profiling duration, as an infinite profiling + * duration may cause out-of-memory errors. + */ +case class ProfilingConfig( + runtimeEventsLogPath: Option[Path] = None, + profilingPath: Option[Path] = None, + profilingTime: Option[FiniteDuration] = None +) diff --git a/engine/language-server/src/main/scala/org/enso/languageserver/data/Config.scala b/engine/language-server/src/main/scala/org/enso/languageserver/data/Config.scala index 8b5e6c40c7..c59cb825a0 100644 --- a/engine/language-server/src/main/scala/org/enso/languageserver/data/Config.scala +++ b/engine/language-server/src/main/scala/org/enso/languageserver/data/Config.scala @@ -1,10 +1,12 @@ package org.enso.languageserver.data +import org.enso.languageserver.boot.ProfilingConfig import org.enso.languageserver.filemanager.ContentRootWithFile import org.enso.logger.masking.{MaskingUtils, ToLogString} import java.io.File import java.nio.file.Files + import scala.concurrent.duration._ /** Configuration of the path watcher. @@ -122,13 +124,15 @@ object ProjectDirectoriesConfig { * @param pathWatcher the path watcher config * @param executionContext the executionContext config * @param directories the configuration of internal directories + * @param profiling the profiling configuration */ case class Config( projectContentRoot: ContentRootWithFile, fileManager: FileManagerConfig, pathWatcher: PathWatcherConfig, executionContext: ExecutionContextConfig, - directories: ProjectDirectoriesConfig + directories: ProjectDirectoriesConfig, + profiling: ProfilingConfig ) extends ToLogString { /** @inheritdoc */ diff --git a/engine/language-server/src/main/scala/org/enso/languageserver/runtime/ApiEventsMonitor.scala b/engine/language-server/src/main/scala/org/enso/languageserver/runtime/ApiEventsMonitor.scala index 84f13b523b..dd2258ff6a 100644 --- a/engine/language-server/src/main/scala/org/enso/languageserver/runtime/ApiEventsMonitor.scala +++ b/engine/language-server/src/main/scala/org/enso/languageserver/runtime/ApiEventsMonitor.scala @@ -8,6 +8,8 @@ import java.nio.charset.StandardCharsets import java.nio.file.{Files, Path, StandardOpenOption} import java.time.Clock +import scala.util.Try + /** Gather messages between the language server and the runtime and write them * to the provided file in CSV format. * @@ -61,12 +63,16 @@ final class ApiEventsMonitor(path: Path, clock: Clock) extends EventsMonitor { } object ApiEventsMonitor { - /** Create default instance of [[ApiEventsMonitor]]. */ - def apply(): ApiEventsMonitor = - new ApiEventsMonitor( - Files.createTempFile("enso-api-events-", ".csv"), - Clock.systemUTC() - ) + /** Create default instance of [[ApiEventsMonitor]]. + * + * @param path the path to the events log file + * @return an instance of [[ApiEventsMonitor]] + */ + def apply(path: Path): Try[ApiEventsMonitor] = Try { + Files.deleteIfExists(path) + Files.createFile(path) + new ApiEventsMonitor(path, Clock.systemUTC()) + } /** Direction of the message. */ sealed trait Direction diff --git a/engine/language-server/src/main/scala/org/enso/languageserver/runtime/ContextRegistry.scala b/engine/language-server/src/main/scala/org/enso/languageserver/runtime/ContextRegistry.scala index 696e4bc6a9..772a6f5b76 100644 --- a/engine/language-server/src/main/scala/org/enso/languageserver/runtime/ContextRegistry.scala +++ b/engine/language-server/src/main/scala/org/enso/languageserver/runtime/ContextRegistry.scala @@ -13,7 +13,6 @@ import org.enso.languageserver.util.UnhandledLogging import org.enso.logger.akka.ActorMessageLogging import org.enso.polyglot.runtime.Runtime.Api import org.enso.polyglot.runtime.Runtime.Api.ContextId -import org.enso.profiling.MethodsSampler import org.enso.searcher.SuggestionsRepo import java.util.UUID @@ -59,15 +58,13 @@ import scala.concurrent.duration._ * @param runtimeFailureMapper mapper for runtime failures * @param runtime reference to the [[RuntimeConnector]] * @param sessionRouter the session router - * @param sampler the methods sampler */ final class ContextRegistry( repo: SuggestionsRepo[Future], config: Config, runtimeFailureMapper: RuntimeFailureMapper, runtime: ActorRef, - sessionRouter: ActorRef, - sampler: MethodsSampler + sessionRouter: ActorRef ) extends Actor with LazyLogging with ActorMessageLogging @@ -75,7 +72,8 @@ final class ContextRegistry( import ContextRegistryProtocol._ - private val timeout: FiniteDuration = config.executionContext.requestTimeout + private val timeout: FiniteDuration = + config.executionContext.requestTimeout override def preStart(): Unit = { context.system.eventStream @@ -110,11 +108,9 @@ final class ContextRegistry( .foreach(_ ! update) case update: Api.ExecutionFailed => - sampler.stop(6.seconds)(context.dispatcher) store.getListener(update.contextId).foreach(_ ! update) case update: Api.ExecutionComplete => - sampler.stop(6.seconds)(context.dispatcher) store.getListener(update.contextId).foreach(_ ! update) case update: Api.ExecutionUpdate => @@ -166,7 +162,6 @@ final class ContextRegistry( } case PushContextRequest(client, contextId, stackItem) => - sampler.start() if (store.hasContext(client.clientId, contextId)) { val item = getRuntimeStackItem(stackItem) val handler = @@ -400,15 +395,13 @@ object ContextRegistry { * @param runtimeFailureMapper mapper for runtime failures * @param runtime reference to the [[RuntimeConnector]] * @param sessionRouter the session router - * @param sampler the methods sampler */ def props( repo: SuggestionsRepo[Future], config: Config, runtimeFailureMapper: RuntimeFailureMapper, runtime: ActorRef, - sessionRouter: ActorRef, - sampler: MethodsSampler + sessionRouter: ActorRef ): Props = Props( new ContextRegistry( @@ -416,8 +409,7 @@ object ContextRegistry { config, runtimeFailureMapper, runtime, - sessionRouter, - sampler + sessionRouter ) ) } diff --git a/engine/language-server/src/test/scala/org/enso/languageserver/boot/resource/RepoInitializationSpec.scala b/engine/language-server/src/test/scala/org/enso/languageserver/boot/resource/RepoInitializationSpec.scala index 0b3b8c209d..0587020c01 100644 --- a/engine/language-server/src/test/scala/org/enso/languageserver/boot/resource/RepoInitializationSpec.scala +++ b/engine/language-server/src/test/scala/org/enso/languageserver/boot/resource/RepoInitializationSpec.scala @@ -3,6 +3,7 @@ package org.enso.languageserver.boot.resource import akka.actor.ActorSystem import akka.testkit._ import org.apache.commons.io.FileUtils +import org.enso.languageserver.boot.ProfilingConfig import org.enso.languageserver.data._ import org.enso.languageserver.event.InitializedEvent import org.enso.languageserver.filemanager.{ContentRoot, ContentRootWithFile} @@ -20,6 +21,7 @@ import org.sqlite.SQLiteException import java.nio.file.{Files, StandardOpenOption} import java.util.UUID + import scala.concurrent.Await import scala.concurrent.duration._ @@ -210,7 +212,8 @@ class RepoInitializationSpec FileManagerConfig(timeout = 3.seconds.dilated), PathWatcherConfig(), ExecutionContextConfig(requestTimeout = 3.seconds.dilated), - ProjectDirectoriesConfig.initialize(root.file) + ProjectDirectoriesConfig.initialize(root.file), + ProfilingConfig() ) } diff --git a/engine/language-server/src/test/scala/org/enso/languageserver/filemanager/ContentRootManagerSpec.scala b/engine/language-server/src/test/scala/org/enso/languageserver/filemanager/ContentRootManagerSpec.scala index 699740864d..b2c7c9e217 100644 --- a/engine/language-server/src/test/scala/org/enso/languageserver/filemanager/ContentRootManagerSpec.scala +++ b/engine/language-server/src/test/scala/org/enso/languageserver/filemanager/ContentRootManagerSpec.scala @@ -3,6 +3,7 @@ package org.enso.languageserver.filemanager import akka.actor.{ActorRef, ActorSystem} import akka.testkit.{TestDuration, TestKit, TestProbe} import org.apache.commons.lang3.SystemUtils +import org.enso.languageserver.boot.ProfilingConfig import org.enso.languageserver.data._ import org.enso.languageserver.filemanager.ContentRootManagerProtocol.{ ContentRootsAddedNotification, @@ -19,6 +20,7 @@ import org.scalatest.{Inside, OptionValues} import java.io.File import java.nio.file.{Path => JPath} import java.util.UUID + import scala.concurrent.duration.DurationInt class ContentRootManagerSpec @@ -46,7 +48,8 @@ class ContentRootManagerSpec FileManagerConfig(timeout = 3.seconds.dilated), PathWatcherConfig(), ExecutionContextConfig(requestTimeout = 3.seconds.dilated), - ProjectDirectoriesConfig.initialize(root.file) + ProjectDirectoriesConfig.initialize(root.file), + ProfilingConfig() ) rootActor = system.actorOf(ContentRootManagerActor.props(config)) rootManager = new ContentRootManagerWrapper(config, rootActor) diff --git a/engine/language-server/src/test/scala/org/enso/languageserver/runtime/ContextEventsListenerSpec.scala b/engine/language-server/src/test/scala/org/enso/languageserver/runtime/ContextEventsListenerSpec.scala index 8a6a31f1c5..54ddfacbac 100644 --- a/engine/language-server/src/test/scala/org/enso/languageserver/runtime/ContextEventsListenerSpec.scala +++ b/engine/language-server/src/test/scala/org/enso/languageserver/runtime/ContextEventsListenerSpec.scala @@ -3,6 +3,7 @@ package org.enso.languageserver.runtime import akka.actor.{ActorRef, ActorSystem} import akka.testkit.{ImplicitSender, TestKit, TestProbe} import org.apache.commons.io.FileUtils +import org.enso.languageserver.boot.ProfilingConfig import org.enso.languageserver.data._ import org.enso.languageserver.event.InitializedEvent import org.enso.languageserver.filemanager.{ @@ -29,6 +30,7 @@ import org.scalatest.wordspec.AnyWordSpecLike import java.nio.file.Files import java.util.UUID + import scala.concurrent.duration._ import scala.concurrent.{Await, Future} import scala.util.{Failure, Success} @@ -453,7 +455,8 @@ class ContextEventsListenerSpec FileManagerConfig(timeout = 3.seconds), PathWatcherConfig(), ExecutionContextConfig(requestTimeout = 3.seconds), - ProjectDirectoriesConfig.initialize(root.file) + ProjectDirectoriesConfig.initialize(root.file), + ProfilingConfig() ) } diff --git a/engine/language-server/src/test/scala/org/enso/languageserver/search/SuggestionsHandlerSpec.scala b/engine/language-server/src/test/scala/org/enso/languageserver/search/SuggestionsHandlerSpec.scala index 778a673a86..ba47929ffe 100644 --- a/engine/language-server/src/test/scala/org/enso/languageserver/search/SuggestionsHandlerSpec.scala +++ b/engine/language-server/src/test/scala/org/enso/languageserver/search/SuggestionsHandlerSpec.scala @@ -4,6 +4,7 @@ import akka.actor.{ActorRef, ActorSystem} import akka.testkit.{ImplicitSender, TestKit, TestProbe} import org.apache.commons.io.FileUtils import org.enso.docs.generator.DocsGenerator +import org.enso.languageserver.boot.ProfilingConfig import org.enso.languageserver.capability.CapabilityProtocol.{ AcquireCapability, CapabilityAcquired @@ -1107,7 +1108,8 @@ class SuggestionsHandlerSpec FileManagerConfig(timeout = 3.seconds), PathWatcherConfig(), ExecutionContextConfig(requestTimeout = 3.seconds), - ProjectDirectoriesConfig.initialize(root.file) + ProjectDirectoriesConfig.initialize(root.file), + ProfilingConfig() ) } diff --git a/engine/language-server/src/test/scala/org/enso/languageserver/websocket/binary/BaseBinaryServerTest.scala b/engine/language-server/src/test/scala/org/enso/languageserver/websocket/binary/BaseBinaryServerTest.scala index 035210e802..d10e7089fe 100644 --- a/engine/language-server/src/test/scala/org/enso/languageserver/websocket/binary/BaseBinaryServerTest.scala +++ b/engine/language-server/src/test/scala/org/enso/languageserver/websocket/binary/BaseBinaryServerTest.scala @@ -6,6 +6,7 @@ import akka.actor.{ActorRef, Props} import akka.http.scaladsl.model.RemoteAddress import com.google.flatbuffers.FlatBufferBuilder import org.apache.commons.io.FileUtils +import org.enso.languageserver.boot.ProfilingConfig import org.enso.languageserver.data.{ Config, ExecutionContextConfig, @@ -45,7 +46,8 @@ class BaseBinaryServerTest extends BinaryServerTestKit { FileManagerConfig(timeout = 3.seconds), PathWatcherConfig(), ExecutionContextConfig(requestTimeout = 3.seconds), - ProjectDirectoriesConfig.initialize(testContentRoot.file) + ProjectDirectoriesConfig.initialize(testContentRoot.file), + ProfilingConfig() ) sys.addShutdownHook(FileUtils.deleteQuietly(testContentRoot.file)) diff --git a/engine/language-server/src/test/scala/org/enso/languageserver/websocket/json/BaseServerTest.scala b/engine/language-server/src/test/scala/org/enso/languageserver/websocket/json/BaseServerTest.scala index 14555a1f53..29fb0fd5b6 100644 --- a/engine/language-server/src/test/scala/org/enso/languageserver/websocket/json/BaseServerTest.scala +++ b/engine/language-server/src/test/scala/org/enso/languageserver/websocket/json/BaseServerTest.scala @@ -12,6 +12,7 @@ import org.enso.editions.{EditionResolver, Editions} import org.enso.jsonrpc.test.JsonRpcServerTestKit import org.enso.jsonrpc.{ClientControllerFactory, Protocol} import org.enso.languageserver.TestClock +import org.enso.languageserver.boot.ProfilingConfig import org.enso.languageserver.boot.resource.{ DirectoriesInitialization, RepoInitialization, @@ -41,7 +42,6 @@ import org.enso.loggingservice.LogLevel import org.enso.pkg.PackageManager import org.enso.polyglot.data.TypeGraph import org.enso.polyglot.runtime.Runtime.Api -import org.enso.profiling.NoopSampler import org.enso.runtimeversionmanager.test.{ FakeEnvironment, TestableThreadSafeFileLockManager @@ -93,7 +93,8 @@ class BaseServerTest FileManagerConfig(timeout = 3.seconds), PathWatcherConfig(), ExecutionContextConfig(requestTimeout = 3.seconds), - ProjectDirectoriesConfig(testContentRoot.file) + ProjectDirectoriesConfig(testContentRoot.file), + ProfilingConfig() ) override def protocol: Protocol = JsonRpc.protocol @@ -189,8 +190,7 @@ class BaseServerTest config, RuntimeFailureMapper(contentRootManagerWrapper), runtimeConnectorProbe.ref, - sessionRouter, - NoopSampler() + sessionRouter ) ) diff --git a/engine/language-server/src/test/scala/org/enso/languageserver/websocket/json/FileManagerTest.scala b/engine/language-server/src/test/scala/org/enso/languageserver/websocket/json/FileManagerTest.scala index c87d5796eb..739d9f8d88 100644 --- a/engine/language-server/src/test/scala/org/enso/languageserver/websocket/json/FileManagerTest.scala +++ b/engine/language-server/src/test/scala/org/enso/languageserver/websocket/json/FileManagerTest.scala @@ -1,19 +1,20 @@ package org.enso.languageserver.websocket.json +import io.circe.literal._ +import io.circe.parser.parse +import org.apache.commons.io.FileUtils +import org.bouncycastle.util.encoders.Hex +import org.enso.languageserver.boot.ProfilingConfig +import org.enso.languageserver.data._ +import org.enso.polyglot.runtime.Runtime.Api +import org.enso.testkit.RetrySpec + import java.io.File import java.nio.file.attribute.BasicFileAttributes import java.nio.file.{Files, Paths} import java.security.MessageDigest import java.util.UUID -import io.circe.literal._ -import io.circe.parser.parse -import org.apache.commons.io.FileUtils -import org.bouncycastle.util.encoders.Hex -import org.enso.languageserver.data._ -import org.enso.polyglot.runtime.Runtime.Api -import org.enso.testkit.RetrySpec - import scala.concurrent.duration._ class FileManagerTest extends BaseServerTest with RetrySpec { @@ -26,7 +27,8 @@ class FileManagerTest extends BaseServerTest with RetrySpec { FileManagerConfig(timeout = 3.seconds), PathWatcherConfig(), ExecutionContextConfig(requestTimeout = 3.seconds), - ProjectDirectoriesConfig.initialize(testContentRoot.file) + ProjectDirectoriesConfig.initialize(testContentRoot.file), + ProfilingConfig() ) } diff --git a/engine/launcher/src/main/scala/org/enso/launcher/cli/LauncherApplication.scala b/engine/launcher/src/main/scala/org/enso/launcher/cli/LauncherApplication.scala index 8b90dba219..3405de9ab7 100644 --- a/engine/launcher/src/main/scala/org/enso/launcher/cli/LauncherApplication.scala +++ b/engine/launcher/src/main/scala/org/enso/launcher/cli/LauncherApplication.scala @@ -679,7 +679,8 @@ object LauncherApplication { logLevel, connectLogger, globalCLIOptions.colorMode, - !disableLogMasking + !disableLogMasking, + None ) initializeApp() diff --git a/engine/runner/src/main/scala/org/enso/runner/LanguageServerApp.scala b/engine/runner/src/main/scala/org/enso/runner/LanguageServerApp.scala index e56ce5eeb7..70101fccc8 100644 --- a/engine/runner/src/main/scala/org/enso/runner/LanguageServerApp.scala +++ b/engine/runner/src/main/scala/org/enso/runner/LanguageServerApp.scala @@ -6,7 +6,9 @@ import org.enso.languageserver.boot.{ } import org.enso.loggingservice.LogLevel -import scala.concurrent.Await +import java.util.concurrent.Semaphore + +import scala.concurrent.{Await, ExecutionContext, Future} import scala.concurrent.duration._ import scala.io.StdIn @@ -14,6 +16,8 @@ import scala.io.StdIn */ object LanguageServerApp { + private val semaphore = new Semaphore(1) + /** Runs a Language Server * * @param config the application config @@ -27,7 +31,7 @@ object LanguageServerApp { ): Unit = { val server = new LanguageServerComponent(config, logLevel) Runtime.getRuntime.addShutdownHook(new Thread(() => { - Await.result(server.stop(), 40.seconds) + stop(server)(config.computeExecutionContext) })) Await.result(server.start(), 1.minute) if (deamonize) { @@ -37,7 +41,31 @@ object LanguageServerApp { } } else { StdIn.readLine() + stop(server)(config.computeExecutionContext) } } + /** Stops the language server. + * + * @param server the language server component + * @param ec the execution context + */ + private def stop( + server: LanguageServerComponent + )(implicit ec: ExecutionContext): Unit = { + Await.ready(synchronize(server.stop()), 40.seconds) + } + + /** Makes sure that the calls to the provided future are synchronized. */ + private def synchronize[A]( + fut: => Future[A] + )(implicit ec: ExecutionContext): Future[A] = { + val task = for { + _ <- Future { semaphore.acquire() } + result <- fut + } yield result + task.onComplete(_ => semaphore.release()) + + task + } } diff --git a/engine/runner/src/main/scala/org/enso/runner/Main.scala b/engine/runner/src/main/scala/org/enso/runner/Main.scala index 77dff86538..0376d67f17 100644 --- a/engine/runner/src/main/scala/org/enso/runner/Main.scala +++ b/engine/runner/src/main/scala/org/enso/runner/Main.scala @@ -7,7 +7,7 @@ import com.typesafe.scalalogging.Logger import org.apache.commons.cli.{Option => CliOption, _} import org.enso.editions.DefaultEdition import org.enso.languageserver.boot -import org.enso.languageserver.boot.LanguageServerConfig +import org.enso.languageserver.boot.{LanguageServerConfig, ProfilingConfig} import org.enso.libraryupload.LibraryUploader.UploadFailedError import org.enso.loggingservice.LogLevel import org.enso.pkg.{Contact, PackageManager, Template} @@ -16,14 +16,14 @@ import org.enso.version.VersionDescription import org.graalvm.polyglot.PolyglotException import java.io.File -import java.nio.file.Path -import java.util.UUID +import java.nio.file.{Path, Paths} +import java.util.{Collections, UUID} import scala.Console.err +import scala.concurrent.duration._ import scala.jdk.CollectionConverters._ -import scala.util.{Failure, Success, Try} import scala.util.control.NonFatal -import java.util.Collections +import scala.util.{Failure, Success, Try} /** The main CLI entry point class. */ object Main { @@ -40,7 +40,10 @@ object Main { private val DOCS_OPTION = "docs" private val PREINSTALL_OPTION = "preinstall-dependencies" private val LANGUAGE_SERVER_OPTION = "server" - private val LANGUAGE_SERVER_PROFILING = "server-profiling" + private val LANGUAGE_SERVER_PROFILING_PATH = "server-profiling-path" + private val LANGUAGE_SERVER_PROFILING_TIME = "server-profiling-time" + private val LANGUAGE_SERVER_PROFILING_EVENTS_LOG_PATH = + "server-profiling-events-log-path" private val DAEMONIZE_OPTION = "daemon" private val INTERFACE_OPTION = "interface" private val RPC_PORT_OPTION = "rpc-port" @@ -153,11 +156,26 @@ object Main { .longOpt(LANGUAGE_SERVER_OPTION) .desc("Runs Language Server") .build() - val lsProfilingOption = CliOption.builder - .longOpt(LANGUAGE_SERVER_PROFILING) - .desc( - "Enables the Language Server profiling. The output is written to system temp directory." - ) + val lsProfilingPathOption = CliOption.builder + .hasArg(true) + .numberOfArgs(1) + .argName("file") + .longOpt(LANGUAGE_SERVER_PROFILING_PATH) + .desc("The path to the Language Server profiling file.") + .build() + val lsProfilingTimeOption = CliOption.builder + .hasArg(true) + .numberOfArgs(1) + .argName("seconds") + .longOpt(LANGUAGE_SERVER_PROFILING_TIME) + .desc("The duration in seconds limiting the profiling time.") + .build() + val lsProfilingEventsLogPathOption = CliOption.builder + .hasArg(true) + .numberOfArgs(1) + .argName("file") + .longOpt(LANGUAGE_SERVER_PROFILING_EVENTS_LOG_PATH) + .desc("The path to the runtime events log file.") .build() val deamonizeOption = CliOption.builder .longOpt(DAEMONIZE_OPTION) @@ -335,7 +353,9 @@ object Main { .addOption(newProjectAuthorNameOpt) .addOption(newProjectAuthorEmailOpt) .addOption(lsOption) - .addOption(lsProfilingOption) + .addOption(lsProfilingPathOption) + .addOption(lsProfilingTimeOption) + .addOption(lsProfilingEventsLogPathOption) .addOption(deamonizeOption) .addOption(interfaceOption) .addOption(rpcPortOption) @@ -823,14 +843,29 @@ object Main { dataPort <- Either .catchNonFatal(dataPortStr.toInt) .leftMap(_ => "Port must be integer") - profilingEnabled = line.hasOption(LANGUAGE_SERVER_PROFILING) + profilingPathStr = + Option(line.getOptionValue(LANGUAGE_SERVER_PROFILING_PATH)) + profilingPath <- Either + .catchNonFatal(profilingPathStr.map(Paths.get(_))) + .leftMap(_ => "Profiling path is invalid") + profilingTimeStr = Option( + line.getOptionValue(LANGUAGE_SERVER_PROFILING_TIME) + ) + profilingTime <- Either + .catchNonFatal(profilingTimeStr.map(_.toInt.seconds)) + .leftMap(_ => "Profiling time should be an integer") + profilingEventsLogPathStr = + Option(line.getOptionValue(LANGUAGE_SERVER_PROFILING_EVENTS_LOG_PATH)) + profilingEventsLogPath <- Either + .catchNonFatal(profilingEventsLogPathStr.map(Paths.get(_))) + .leftMap(_ => "Profiling events log path is invalid") } yield boot.LanguageServerConfig( interface, rpcPort, dataPort, rootId, rootPath, - profilingEnabled + ProfilingConfig(profilingEventsLogPath, profilingPath, profilingTime) ) /** Prints the version of the Enso executable. diff --git a/lib/scala/json-rpc-server/src/main/scala/org/enso/jsonrpc/JsonRpcServer.scala b/lib/scala/json-rpc-server/src/main/scala/org/enso/jsonrpc/JsonRpcServer.scala index 87c2d5251e..dfcbb94167 100644 --- a/lib/scala/json-rpc-server/src/main/scala/org/enso/jsonrpc/JsonRpcServer.scala +++ b/lib/scala/json-rpc-server/src/main/scala/org/enso/jsonrpc/JsonRpcServer.scala @@ -1,7 +1,6 @@ package org.enso.jsonrpc import java.util.UUID - import akka.NotUsed import akka.actor.{ActorRef, ActorSystem, Props} import akka.http.scaladsl.Http @@ -10,6 +9,7 @@ import akka.http.scaladsl.server.Directives._ import akka.http.scaladsl.server.Route import akka.stream.scaladsl.{Flow, Sink, Source} import akka.stream.{Materializer, OverflowStrategy} +import com.typesafe.scalalogging.LazyLogging import scala.concurrent.duration._ import scala.concurrent.{ExecutionContext, Future} @@ -31,7 +31,7 @@ class JsonRpcServer( )( implicit val system: ActorSystem, implicit val materializer: Materializer -) { +) extends LazyLogging { implicit val ec: ExecutionContext = system.dispatcher @@ -55,6 +55,9 @@ class JsonRpcServer( _.toStrict(config.lazyMessageTimeout) .map(msg => MessageHandler.WebMessage(msg.text)) ) + .wireTap { webMessage => + logger.trace(s"Received text message: ${webMessage.message}.") + } .to( Sink.actorRef[MessageHandler.WebMessage]( messageHandler, @@ -78,6 +81,9 @@ class JsonRpcServer( NotUsed } .map((outMsg: MessageHandler.WebMessage) => TextMessage(outMsg.message)) + .wireTap { textMessage => + logger.trace(s"Sent text message ${textMessage.text}.") + } Flow.fromSinkAndSource(incomingMessages, outgoingMessages) } diff --git a/lib/scala/logging-service/src/main/scala/org/enso/loggingservice/JavaLoggingLogHandler.scala b/lib/scala/logging-service/src/main/scala/org/enso/loggingservice/JavaLoggingLogHandler.scala index fdee9b6284..691b8363e4 100644 --- a/lib/scala/logging-service/src/main/scala/org/enso/loggingservice/JavaLoggingLogHandler.scala +++ b/lib/scala/logging-service/src/main/scala/org/enso/loggingservice/JavaLoggingLogHandler.scala @@ -2,9 +2,7 @@ package org.enso.loggingservice import org.enso.loggingservice.internal.{InternalLogMessage, LoggerConnection} -import java.io.{File, FileWriter, Writer} -import java.nio.charset.StandardCharsets -import java.util.logging.{Handler, Level, LogRecord, XMLFormatter} +import java.util.logging.{Handler, Level, LogRecord} /** A [[Handler]] implementation that allows to use the logging service as a * backend for [[java.util.logging]]. @@ -27,12 +25,6 @@ class JavaLoggingLogHandler( exception = Option(record.getThrown) ) connection.send(message) - val w = JavaLoggingLogHandler.log; - if (w != null) { - val f = new XMLFormatter() - val out = f.format(record) - w.write(out); - } } } @@ -81,17 +73,4 @@ object JavaLoggingLogHandler { case LogLevel.Debug => Level.FINE case LogLevel.Trace => Level.ALL } - - var log: Writer = null - def registerLogFile(file: File): Unit = { - if (this.log != null) { - this.log.close() - } - val w = new FileWriter(file, StandardCharsets.UTF_8, false) - w.write( - "\n" - ) - this.log = w - } - } diff --git a/lib/scala/logging-service/src/main/scala/org/enso/loggingservice/LogLevel.scala b/lib/scala/logging-service/src/main/scala/org/enso/loggingservice/LogLevel.scala index 2949ec973d..6949d17675 100644 --- a/lib/scala/logging-service/src/main/scala/org/enso/loggingservice/LogLevel.scala +++ b/lib/scala/logging-service/src/main/scala/org/enso/loggingservice/LogLevel.scala @@ -132,4 +132,16 @@ object LogLevel { case Debug => akka.event.Logging.DebugLevel case Trace => akka.event.Logging.DebugLevel } + + /** Converts our internal [[LogLevel]] to the corresponding instance of + * Java log level. + */ + def toJava(logLevel: LogLevel): java.util.logging.Level = logLevel match { + case Off => java.util.logging.Level.OFF + case Error => java.util.logging.Level.SEVERE + case Warning => java.util.logging.Level.WARNING + case Info => java.util.logging.Level.INFO + case Debug => java.util.logging.Level.FINER + case Trace => java.util.logging.Level.FINEST + } } diff --git a/lib/scala/logging-service/src/main/scala/org/enso/loggingservice/LoggingServiceSetupHelper.scala b/lib/scala/logging-service/src/main/scala/org/enso/loggingservice/LoggingServiceSetupHelper.scala index eb24cd4c97..ed6a06f2de 100644 --- a/lib/scala/logging-service/src/main/scala/org/enso/loggingservice/LoggingServiceSetupHelper.scala +++ b/lib/scala/logging-service/src/main/scala/org/enso/loggingservice/LoggingServiceSetupHelper.scala @@ -1,16 +1,11 @@ package org.enso.loggingservice -import java.nio.file.Path - import akka.http.scaladsl.model.Uri import com.typesafe.scalalogging.Logger import org.enso.logger.masking.Masking -import org.enso.loggingservice.printers.{ - FileOutputPrinter, - Printer, - StderrPrinter, - StderrPrinterWithColors -} +import org.enso.loggingservice.printers._ + +import java.nio.file.Path import scala.concurrent.duration.DurationInt import scala.concurrent.{Await, ExecutionContext, Future, Promise} @@ -54,7 +49,8 @@ abstract class LoggingServiceSetupHelper(implicit logLevel: Option[LogLevel], connectToExternalLogger: Option[Uri], colorMode: ColorMode, - logMasking: Boolean + logMasking: Boolean, + profilingLog: Option[Path] ): Unit = { val actualLogLevel = logLevel.getOrElse(defaultLogLevel) Masking.setup(logMasking) @@ -62,7 +58,7 @@ abstract class LoggingServiceSetupHelper(implicit case Some(uri) => setupLoggingConnection(uri, actualLogLevel) case None => - setupLoggingServer(actualLogLevel, colorMode) + setupLoggingServer(actualLogLevel, colorMode, profilingLog) } } @@ -114,7 +110,8 @@ abstract class LoggingServiceSetupHelper(implicit private def setupLoggingServer( logLevel: LogLevel, - colorMode: ColorMode + colorMode: ColorMode, + profilingLog: Option[Path] ): Unit = { val printExceptionsInStderr = implicitly[Ordering[LogLevel]].compare(logLevel, LogLevel.Debug) >= 0 @@ -132,10 +129,11 @@ abstract class LoggingServiceSetupHelper(implicit suffix = logFileSuffix, printExceptions = true ) + val profilingPrinterOpt = profilingLog.map(new FileXmlPrinter(_)) Seq( stderrPrinter(colorMode, printExceptionsInStderr), filePrinter - ) + ) ++ profilingPrinterOpt } catch { case NonFatal(error) => logger.error( diff --git a/lib/scala/logging-service/src/main/scala/org/enso/loggingservice/printers/FileOutputPrinter.scala b/lib/scala/logging-service/src/main/scala/org/enso/loggingservice/printers/FileOutputPrinter.scala index de9a498074..6b7716eafe 100644 --- a/lib/scala/logging-service/src/main/scala/org/enso/loggingservice/printers/FileOutputPrinter.scala +++ b/lib/scala/logging-service/src/main/scala/org/enso/loggingservice/printers/FileOutputPrinter.scala @@ -70,7 +70,7 @@ object FileOutputPrinter { def create( logDirectory: Path, suffix: String, - printExceptions: Boolean = true + printExceptions: Boolean ): FileOutputPrinter = new FileOutputPrinter(logDirectory, suffix, printExceptions) } diff --git a/lib/scala/logging-service/src/main/scala/org/enso/loggingservice/printers/FileXmlPrinter.scala b/lib/scala/logging-service/src/main/scala/org/enso/loggingservice/printers/FileXmlPrinter.scala new file mode 100644 index 0000000000..575ca1d86e --- /dev/null +++ b/lib/scala/logging-service/src/main/scala/org/enso/loggingservice/printers/FileXmlPrinter.scala @@ -0,0 +1,61 @@ +package org.enso.loggingservice.printers + +import org.enso.loggingservice.LogLevel +import org.enso.loggingservice.internal.protocol.WSLogMessage + +import java.io.PrintWriter +import java.nio.file.{Files, Path, StandardOpenOption} +import java.util.logging.{LogRecord, XMLFormatter} + +/** Creates a new file in [[logPath]] and writes incoming log messages to + * this file in XML format. + * + * @param logPath the file path to log + */ +class FileXmlPrinter(logPath: Path) extends Printer { + + private val writer = initializeWriter() + private val formatter = new XMLFormatter() + + /** @inheritdoc */ + override def print(message: WSLogMessage): Unit = { + val lines = formatter.format(toLogRecord(message)) + writer.print(lines) + } + + /** @inheritdoc */ + override def shutdown(): Unit = { + writer.flush() + writer.close() + } + + /** Opens the log file for writing. */ + private def initializeWriter(): PrintWriter = { + Option(logPath.getParent).foreach(Files.createDirectories(_)) + val writer = new PrintWriter( + Files.newBufferedWriter( + logPath, + StandardOpenOption.CREATE, + StandardOpenOption.TRUNCATE_EXISTING, + StandardOpenOption.WRITE + ) + ) + writer.println(FileXmlPrinter.Header) + writer + } + + /** Converts [[WSLogMessage]] to java [[LogRecord]]. */ + private def toLogRecord(wsLogMessage: WSLogMessage): LogRecord = { + val record = + new LogRecord(LogLevel.toJava(wsLogMessage.level), wsLogMessage.message) + record.setInstant(wsLogMessage.timestamp) + record.setLoggerName(wsLogMessage.group) + record + } + +} +object FileXmlPrinter { + + private val Header: String = + "" +} diff --git a/lib/scala/profiling-utils/src/main/scala/org/enso/profiling/TempFileSampler.scala b/lib/scala/profiling-utils/src/main/scala/org/enso/profiling/FileSampler.scala similarity index 60% rename from lib/scala/profiling-utils/src/main/scala/org/enso/profiling/TempFileSampler.scala rename to lib/scala/profiling-utils/src/main/scala/org/enso/profiling/FileSampler.scala index 18b2c58b1d..0aa2a9dc1d 100644 --- a/lib/scala/profiling-utils/src/main/scala/org/enso/profiling/TempFileSampler.scala +++ b/lib/scala/profiling-utils/src/main/scala/org/enso/profiling/FileSampler.scala @@ -3,10 +3,9 @@ package org.enso.profiling import org.netbeans.modules.sampler.Sampler import java.io.{DataOutputStream, File, FileOutputStream} -import java.nio.file.Files import java.util.concurrent.{CompletableFuture, Executor, Executors} -import scala.concurrent.duration.Duration +import scala.concurrent.duration.FiniteDuration import scala.util.Using /** Gathers application performance statistics that can be visualised in Java @@ -14,16 +13,11 @@ import scala.util.Using * * @param output the output stream to write the collected statistics to */ -final class TempFileSampler(output: File) extends MethodsSampler { +final class FileSampler(output: File) extends MethodsSampler { private val sampler: Sampler = Sampler.createSampler(getClass.getSimpleName) private var samplingStarted: Boolean = false - def getSiblingFile(ext: String): File = { - val newName = output.getName.replace(".npss", ext) - new File(output.getParent, newName) - } - /** @inheritdoc */ def start(): Unit = this.synchronized { @@ -45,7 +39,7 @@ final class TempFileSampler(output: File) extends MethodsSampler { } /** @inheritdoc */ - def stop(delay: Duration)(implicit ec: Executor): Unit = + def stop(delay: FiniteDuration)(implicit ec: Executor): Unit = this.synchronized { val executor = Executors.newSingleThreadScheduledExecutor() @@ -58,22 +52,4 @@ final class TempFileSampler(output: File) extends MethodsSampler { ) .whenComplete((_, _) => executor.shutdown()) } - - /** @return `true` if the sampling is started. */ - def isSamplingStarted: Boolean = - this.samplingStarted -} -object TempFileSampler { - - /** Create an instance of [[MethodsSampler]] that writes the data to the - * temporary `.npss` file with the provided prefix. - * - * @param prefix the prefix of the temp file. - * @return the [[MethodsSampler]] instance - */ - def apply(prefix: String): TempFileSampler = { - val path = Files.createTempFile(s"$prefix-", ".npss") - Files.deleteIfExists(path) - new TempFileSampler(path.toFile) - } } diff --git a/lib/scala/profiling-utils/src/main/scala/org/enso/profiling/MethodsSampler.scala b/lib/scala/profiling-utils/src/main/scala/org/enso/profiling/MethodsSampler.scala index b74173a821..2e4d6a872b 100644 --- a/lib/scala/profiling-utils/src/main/scala/org/enso/profiling/MethodsSampler.scala +++ b/lib/scala/profiling-utils/src/main/scala/org/enso/profiling/MethodsSampler.scala @@ -2,7 +2,7 @@ package org.enso.profiling import java.util.concurrent.Executor -import scala.concurrent.duration.Duration +import scala.concurrent.duration.FiniteDuration /** Sampler gathers the application performance statistics. */ trait MethodsSampler { @@ -19,5 +19,5 @@ trait MethodsSampler { * @param delay the duration to wait before stopping * @param ec the execution context */ - def stop(delay: Duration)(implicit ec: Executor): Unit + def stop(delay: FiniteDuration)(implicit ec: Executor): Unit } diff --git a/lib/scala/profiling-utils/src/main/scala/org/enso/profiling/NoopSampler.scala b/lib/scala/profiling-utils/src/main/scala/org/enso/profiling/NoopSampler.scala index 78a5ba6630..9ef0ab06ea 100644 --- a/lib/scala/profiling-utils/src/main/scala/org/enso/profiling/NoopSampler.scala +++ b/lib/scala/profiling-utils/src/main/scala/org/enso/profiling/NoopSampler.scala @@ -2,7 +2,7 @@ package org.enso.profiling import java.util.concurrent.Executor -import scala.concurrent.duration.Duration +import scala.concurrent.duration.FiniteDuration /** Sampler that does nothing. */ final class NoopSampler extends MethodsSampler { @@ -14,7 +14,7 @@ final class NoopSampler extends MethodsSampler { override def stop(): Unit = () /** @inheritdoc */ - override def stop(delay: Duration)(implicit ec: Executor): Unit = () + override def stop(delay: FiniteDuration)(implicit ec: Executor): Unit = () } object NoopSampler { diff --git a/lib/scala/project-manager/src/main/scala/org/enso/projectmanager/boot/Cli.scala b/lib/scala/project-manager/src/main/scala/org/enso/projectmanager/boot/Cli.scala index 9b0d674613..481e085180 100644 --- a/lib/scala/project-manager/src/main/scala/org/enso/projectmanager/boot/Cli.scala +++ b/lib/scala/project-manager/src/main/scala/org/enso/projectmanager/boot/Cli.scala @@ -7,12 +7,14 @@ import scala.util.Try object Cli { - val JSON_OPTION = "json" - val HELP_OPTION = "help" - val NO_LOG_MASKING = "no-log-masking" - val VERBOSE_OPTION = "verbose" - val VERSION_OPTION = "version" - val ENABLE_PROFILING = "profiling" + val JSON_OPTION = "json" + val HELP_OPTION = "help" + val NO_LOG_MASKING = "no-log-masking" + val VERBOSE_OPTION = "verbose" + val VERSION_OPTION = "version" + val PROFILING_PATH = "profiling-path" + val PROFILING_TIME = "profiling-time" + val PROFILING_EVENTS_LOG_PATH = "profiling-events-log-path" object option { @@ -47,9 +49,30 @@ object Cli { ) .build() - val enableProfiling: cli.Option = cli.Option.builder - .longOpt(ENABLE_PROFILING) - .desc("Enables the application profiling.") + val profilingPath: cli.Option = cli.Option.builder + .hasArg(true) + .numberOfArgs(1) + .argName("file") + .longOpt(PROFILING_PATH) + .desc("The path to profiling file. Enables the application profiling.") + .build() + + val profilingTime: cli.Option = cli.Option.builder + .hasArg(true) + .numberOfArgs(1) + .argName("seconds") + .longOpt(PROFILING_TIME) + .desc("The duration in seconds limiting the application profiling time.") + .build() + + val profilingEventsLogPath: cli.Option = cli.Option.builder + .hasArg(true) + .numberOfArgs(1) + .argName("file") + .longOpt(PROFILING_EVENTS_LOG_PATH) + .desc( + "The path to the runtime events log file. Enables the runtime events logging." + ) .build() } @@ -60,7 +83,9 @@ object Cli { .addOption(option.version) .addOption(option.json) .addOption(option.noLogMasking) - .addOption(option.enableProfiling) + .addOption(option.profilingPath) + .addOption(option.profilingTime) + .addOption(option.profilingEventsLogPath) /** Parse the command line options. */ def parse(args: Array[String]): Either[String, cli.CommandLine] = { diff --git a/lib/scala/project-manager/src/main/scala/org/enso/projectmanager/boot/ProjectManager.scala b/lib/scala/project-manager/src/main/scala/org/enso/projectmanager/boot/ProjectManager.scala index db4b23b9d1..e7a750c78d 100644 --- a/lib/scala/project-manager/src/main/scala/org/enso/projectmanager/boot/ProjectManager.scala +++ b/lib/scala/project-manager/src/main/scala/org/enso/projectmanager/boot/ProjectManager.scala @@ -23,6 +23,7 @@ import zio.console._ import zio.interop.catz.core._ import java.io.IOException +import java.nio.file.{FileAlreadyExistsException, Files, Path, Paths} import java.util.concurrent.ScheduledThreadPoolExecutor import scala.concurrent.duration._ @@ -120,23 +121,99 @@ object ProjectManager extends App with LazyLogging { } } + /** Parses and validates the command line arguments. + * + * @param options the command line arguments + */ + def parseOpts( + options: CommandLine + ): ZIO[ZEnv, Throwable, ProjectManagerOptions] = { + val parseProfilingPath = ZIO + .effect { + Option(options.getOptionValue(Cli.PROFILING_PATH)) + .map(Paths.get(_).toAbsolutePath) + } + .flatMap { + case pathOpt @ Some(path) => + ZIO.ifM(ZIO.effect(Files.isDirectory(path)))( + onTrue = putStrLnErr( + s"Error: ${Cli.PROFILING_PATH} is a directory: $path" + ) *> + ZIO.fail(new FileAlreadyExistsException(path.toString)), + onFalse = ZIO.succeed(pathOpt) + ) + case None => + ZIO.succeed(None) + } + .catchAll { err => + putStrLnErr(s"Invalid ${Cli.PROFILING_PATH} argument.") *> ZIO.fail(err) + } + + val parseProfilingTime = ZIO + .effect { + Option(options.getOptionValue(Cli.PROFILING_TIME)) + .map(_.toInt.seconds) + } + .catchAll { err => + putStrLnErr(s"Invalid ${Cli.PROFILING_TIME} argument.") *> ZIO.fail(err) + } + + val parseProfilingEventsLogPath = ZIO + .effect { + Option(options.getOptionValue(Cli.PROFILING_EVENTS_LOG_PATH)) + .map(Paths.get(_).toAbsolutePath) + } + .flatMap { + case pathOpt @ Some(path) => + ZIO.ifM(ZIO.effect(Files.isDirectory(path)))( + onTrue = putStrLnErr( + s"Error: ${Cli.PROFILING_EVENTS_LOG_PATH} is a directory: $path" + ) *> + ZIO.fail(new FileAlreadyExistsException(path.toString)), + onFalse = ZIO.succeed(pathOpt) + ) + case None => + ZIO.succeed(None) + } + .catchAll { err => + putStrLnErr(s"Invalid ${Cli.PROFILING_EVENTS_LOG_PATH} argument.") *> + ZIO.fail(err) + } + + for { + profilingEventsLogPath <- parseProfilingEventsLogPath + profilingPath <- parseProfilingPath + profilingTime <- parseProfilingTime + } yield ProjectManagerOptions( + profilingEventsLogPath, + profilingPath, + profilingTime + ) + } + /** The main function of the application, which will be passed the command-line * arguments to the program and has to return an `IO` with the errors fully handled. */ - def runOpts(options: CommandLine): ZIO[ZEnv, IOException, ExitCode] = { + def runOpts(options: CommandLine): ZIO[ZEnv, Throwable, ExitCode] = { if (options.hasOption(Cli.HELP_OPTION)) { ZIO.effectTotal(Cli.printHelp()) *> ZIO.succeed(SuccessExitCode) } else if (options.hasOption(Cli.VERSION_OPTION)) { displayVersion(options.hasOption(Cli.JSON_OPTION)) } else { - val verbosity = options.getOptions.count(_ == Cli.option.verbose) - val logMasking = !options.hasOption(Cli.NO_LOG_MASKING) - val profilingEnabled = options.hasOption(Cli.ENABLE_PROFILING) + val verbosity = options.getOptions.count(_ == Cli.option.verbose) + val logMasking = !options.hasOption(Cli.NO_LOG_MASKING) logger.info("Starting Project Manager...") for { - logLevel <- setupLogging(verbosity, logMasking) - procConf = MainProcessConfig(logLevel, profilingEnabled) + opts <- parseOpts(options) + profilingLog = opts.profilingPath.map(getSiblingFile(_, ".log")) + logLevel <- setupLogging(verbosity, logMasking, profilingLog) + procConf = MainProcessConfig( + logLevel, + opts.profilingRuntimeEventsLog, + opts.profilingPath, + opts.profilingTime + ) exitCode <- mainProcess(procConf).fold( th => { logger.error("Main process execution failed.", th) @@ -150,7 +227,8 @@ object ProjectManager extends App with LazyLogging { private def setupLogging( verbosityLevel: Int, - logMasking: Boolean + logMasking: Boolean, + profilingLog: Option[Path] ): ZIO[Console, IOException, LogLevel] = { val level = verbosityLevel match { case 0 => LogLevel.Info @@ -164,7 +242,7 @@ object ProjectManager extends App with LazyLogging { ZIO .effect { - Logging.setup(Some(level), None, colorMode, logMasking) + Logging.setup(Some(level), None, colorMode, logMasking, profilingLog) } .catchAll { exception => putStrLnErr(s"Failed to setup the logger: $exception") @@ -203,4 +281,12 @@ object ProjectManager extends App with LazyLogging { ) } + private def getSiblingFile(file: Path, ext: String): Path = { + val fileName = file.getFileName.toString + val extensionIndex = fileName.lastIndexOf(".") + val newName = + if (extensionIndex > 0) fileName.substring(0, extensionIndex) + ext + else fileName + ext + file.getParent.resolve(newName) + } } diff --git a/lib/scala/project-manager/src/main/scala/org/enso/projectmanager/boot/ProjectManagerOptions.scala b/lib/scala/project-manager/src/main/scala/org/enso/projectmanager/boot/ProjectManagerOptions.scala new file mode 100644 index 0000000000..42a1174479 --- /dev/null +++ b/lib/scala/project-manager/src/main/scala/org/enso/projectmanager/boot/ProjectManagerOptions.scala @@ -0,0 +1,17 @@ +package org.enso.projectmanager.boot + +import java.nio.file.Path + +import scala.concurrent.duration.FiniteDuration + +/** The runtime options. + * + * @param profilingRuntimeEventsLog the path to the runtime events log file + * @param profilingPath the path to the profiling output file + * @param profilingTime the time limiting the profiling duration + */ +case class ProjectManagerOptions( + profilingRuntimeEventsLog: Option[Path], + profilingPath: Option[Path], + profilingTime: Option[FiniteDuration] +) diff --git a/lib/scala/project-manager/src/main/scala/org/enso/projectmanager/boot/configuration.scala b/lib/scala/project-manager/src/main/scala/org/enso/projectmanager/boot/configuration.scala index ccb4d1992b..7b4bb6f4ca 100644 --- a/lib/scala/project-manager/src/main/scala/org/enso/projectmanager/boot/configuration.scala +++ b/lib/scala/project-manager/src/main/scala/org/enso/projectmanager/boot/configuration.scala @@ -3,6 +3,7 @@ package org.enso.projectmanager.boot import org.enso.loggingservice.LogLevel import java.io.File +import java.nio.file.Path import scala.concurrent.duration.FiniteDuration @@ -12,11 +13,15 @@ object configuration { * main project manager process. * * @param logLevel the logging level - * @param profilingEnabled if the profiling is enabled + * @param profilingEventsLogPath the path to the runtime events log file + * @param profilingPath the path to the profiling out file + * @param profilingTime the time limiting the profiling duration */ case class MainProcessConfig( logLevel: LogLevel, - profilingEnabled: Boolean + profilingEventsLogPath: Option[Path], + profilingPath: Option[Path], + profilingTime: Option[FiniteDuration] ) /** A configuration object for properties of the Project Manager. diff --git a/lib/scala/project-manager/src/main/scala/org/enso/projectmanager/infrastructure/languageserver/ExecutorWithUnlimitedPool.scala b/lib/scala/project-manager/src/main/scala/org/enso/projectmanager/infrastructure/languageserver/ExecutorWithUnlimitedPool.scala index 1664dc7b52..d4250cc2d2 100644 --- a/lib/scala/project-manager/src/main/scala/org/enso/projectmanager/infrastructure/languageserver/ExecutorWithUnlimitedPool.scala +++ b/lib/scala/project-manager/src/main/scala/org/enso/projectmanager/infrastructure/languageserver/ExecutorWithUnlimitedPool.scala @@ -95,8 +95,23 @@ object ExecutorWithUnlimitedPool extends LanguageServerExecutor { environment = distributionConfiguration.environment, loggerConnection = descriptor.deferredLoggingServiceEndpoint ) + val profilingPathArguments = + descriptor.profilingPath.toSeq + .flatMap(path => Seq("--server-profiling-path", path.toString)) + val profilingTimeArguments = + descriptor.profilingTime.toSeq + .flatMap(time => + Seq("--server-profiling-time", time.toSeconds.toString) + ) + val profilingEventsLogPathArguments = + descriptor.profilingEventsLogPath.toSeq + .flatMap(path => + Seq("--server-profiling-events-log-path", path.toString) + ) val additionalArguments = - Option.when(descriptor.profilingEnabled)("--server-profiling").toSeq + profilingPathArguments ++ + profilingTimeArguments ++ + profilingEventsLogPathArguments val runSettings = runner .startLanguageServer( options = options, diff --git a/lib/scala/project-manager/src/main/scala/org/enso/projectmanager/infrastructure/languageserver/LanguageServerController.scala b/lib/scala/project-manager/src/main/scala/org/enso/projectmanager/infrastructure/languageserver/LanguageServerController.scala index 6746042641..7afdeaea24 100644 --- a/lib/scala/project-manager/src/main/scala/org/enso/projectmanager/infrastructure/languageserver/LanguageServerController.scala +++ b/lib/scala/project-manager/src/main/scala/org/enso/projectmanager/infrastructure/languageserver/LanguageServerController.scala @@ -79,7 +79,9 @@ class LanguageServerController( engineVersion = engineVersion, jvmSettings = distributionConfiguration.defaultJVMSettings, discardOutput = distributionConfiguration.shouldDiscardChildOutput, - profilingEnabled = processConfig.profilingEnabled, + profilingEventsLogPath = processConfig.profilingEventsLogPath, + profilingPath = processConfig.profilingPath, + profilingTime = processConfig.profilingTime, deferredLoggingServiceEndpoint = loggingServiceDescriptor.getEndpoint ) diff --git a/lib/scala/project-manager/src/main/scala/org/enso/projectmanager/infrastructure/languageserver/LanguageServerDescriptor.scala b/lib/scala/project-manager/src/main/scala/org/enso/projectmanager/infrastructure/languageserver/LanguageServerDescriptor.scala index 7eb61eee3d..a185b05623 100644 --- a/lib/scala/project-manager/src/main/scala/org/enso/projectmanager/infrastructure/languageserver/LanguageServerDescriptor.scala +++ b/lib/scala/project-manager/src/main/scala/org/enso/projectmanager/infrastructure/languageserver/LanguageServerDescriptor.scala @@ -1,14 +1,16 @@ package org.enso.projectmanager.infrastructure.languageserver -import java.util.UUID - import akka.http.scaladsl.model.Uri import nl.gn0s1s.bump.SemVer import org.enso.projectmanager.boot.configuration.NetworkConfig import org.enso.projectmanager.versionmanagement.DistributionConfiguration import org.enso.runtimeversionmanager.runner.JVMSettings +import java.nio.file.Path +import java.util.UUID + import scala.concurrent.Future +import scala.concurrent.duration.FiniteDuration /** A descriptor specifying options related to starting a Language Server. * @@ -23,7 +25,9 @@ import scala.concurrent.Future * @param jvmSettings settings to use for the JVM that will host the engine * @param discardOutput specifies if the process output should be discarded or * printed to parent's streams - * @param profilingEnabled enables the language server profiling + * @param profilingEventsLogPath the path to the runtime events log file + * @param profilingPath the language server profiling file path + * @param profilingTime the time limiting the profiling duration * @param deferredLoggingServiceEndpoint a future that is completed once the * logging service has been fully set-up; * if the child component should connect @@ -39,6 +43,8 @@ case class LanguageServerDescriptor( engineVersion: SemVer, jvmSettings: JVMSettings, discardOutput: Boolean, - profilingEnabled: Boolean, + profilingEventsLogPath: Option[Path], + profilingPath: Option[Path], + profilingTime: Option[FiniteDuration], deferredLoggingServiceEndpoint: Future[Option[Uri]] ) diff --git a/lib/scala/project-manager/src/test/scala/org/enso/projectmanager/BaseServerSpec.scala b/lib/scala/project-manager/src/test/scala/org/enso/projectmanager/BaseServerSpec.scala index 19d2384e4e..e417e5295b 100644 --- a/lib/scala/project-manager/src/test/scala/org/enso/projectmanager/BaseServerSpec.scala +++ b/lib/scala/project-manager/src/test/scala/org/enso/projectmanager/BaseServerSpec.scala @@ -71,7 +71,7 @@ class BaseServerSpec extends JsonRpcServerTestKit with BeforeAndAfterAll { val debugLogs: Boolean = false /** Enables the application profiling. */ - val profilingEnabled: Boolean = false + val profilingPath: Option[Path] = None /** Tests can override this to allow child process output to be displayed. */ val debugChildLogs: Boolean = false @@ -87,8 +87,10 @@ class BaseServerSpec extends JsonRpcServerTestKit with BeforeAndAfterAll { val processConfig: MainProcessConfig = MainProcessConfig( - logLevel = if (debugLogs) LogLevel.Trace else LogLevel.Off, - profilingEnabled = profilingEnabled + logLevel = if (debugLogs) LogLevel.Trace else LogLevel.Off, + profilingPath = profilingPath, + profilingTime = None, + profilingEventsLogPath = None ) val testClock =