It's really easy to make a typo otherwise
This commit is contained in:
Hubert Plociniczak 2023-11-09 17:51:20 +01:00
parent 4bc2538b73
commit 08fbc71a8d
16 changed files with 204 additions and 237 deletions

View File

@ -54,17 +54,15 @@ public final class InvalidateModulesIndexCommand extends AsynchronousCommand {
} catch (InterruptedException ie) {
logger.log(Level.WARNING, "Failed to acquire lock: interrupted", ie);
} finally {
if (writeCompilationLockTimestamp != 0) {
logLockRelease(
logger,
"write compilation",
writeCompilationLockTimestamp,
() -> {
ctx.locking().releaseWriteCompilationLock();
logger.log(
Level.FINEST,
"Kept write compilation lock [{0}] for {1} milliseconds.",
new Object[] {
this.getClass().getSimpleName(),
System.currentTimeMillis() - writeCompilationLockTimestamp
return BoxedUnit.UNIT;
});
}
}
return BoxedUnit.UNIT;
},

View File

@ -58,24 +58,22 @@ public class SetExecutionEnvironmentCommand extends AsynchronousCommand {
} catch (InterruptedException ie) {
logger.log(Level.WARNING, "Failed to acquire lock: interrupted", ie);
} finally {
if (writeLockTimestamp != 0) {
logLockRelease(
logger,
"write compilation",
writeLockTimestamp,
() -> {
ctx.locking().releaseWriteCompilationLock();
logger.log(
Level.FINEST,
"Kept write compilation lock [{0}] for {1} milliseconds",
new Object[] {
this.getClass().getSimpleName(), System.currentTimeMillis() - writeLockTimestamp
return BoxedUnit.UNIT;
});
}
if (contextLockTimestamp != 0) {
logLockRelease(
logger,
"context",
contextLockTimestamp,
() -> {
ctx.locking().releaseContextLock(contextId);
logger.log(
Level.FINEST,
"Kept context lock [{0}] for {1} milliseconds",
new Object[] {
this.getClass().getSimpleName(), System.currentTimeMillis() - contextLockTimestamp
return BoxedUnit.UNIT;
});
}
}
}
}

View File

@ -5,6 +5,7 @@ import org.enso.interpreter.instrument.execution.RuntimeContext;
import org.enso.interpreter.runtime.SerializationManager;
import org.enso.pkg.QualifiedName;
import org.enso.polyglot.CompilationStage;
import scala.runtime.BoxedUnit;
/** The job that serializes module. */
public final class SerializeModuleJob extends BackgroundJob<Void> {
@ -50,18 +51,15 @@ public final class SerializeModuleJob extends BackgroundJob<Void> {
.getLogger()
.log(Level.WARNING, "Failed to acquire lock: interrupted", ie);
} finally {
if (writeLockTimestamp != 0) {
logLockRelease(
ctx.executionService().getLogger(),
"write compilation",
writeLockTimestamp,
() -> {
ctx.locking().releaseWriteCompilationLock();
ctx.executionService()
.getLogger()
.log(
Level.FINEST,
"Kept write compilation lock [{0}] for {1} milliseconds",
new Object[] {
this.getClass().getSimpleName(), System.currentTimeMillis() - writeLockTimestamp
return BoxedUnit.UNIT;
});
}
}
return null;
}

View File

@ -32,39 +32,24 @@ class CloseFileCmd(request: Api.CloseFileNotification)
case ie: InterruptedException =>
logger.log(Level.WARNING, "Failed to acquire lock: interrupted", ie)
} finally {
if (pendingEditsLockTimestamp != 0) {
logLockRelease(
logger,
"pending edits",
pendingEditsLockTimestamp,
ctx.locking.releasePendingEditsLock()
logger.log(
Level.FINEST,
"Kept pending edits lock [{0}] for {1} milliseconds",
Array(
getClass.getSimpleName,
System.currentTimeMillis - pendingEditsLockTimestamp
)
)
}
if (fileLockTimestamp != 0) {
logLockRelease(
logger,
"file",
fileLockTimestamp,
ctx.locking.releaseFileLock(request.path)
logger.log(
Level.FINEST,
"Kept file lock [{0}] for {1} milliseconds",
Array(
getClass.getSimpleName,
System.currentTimeMillis - fileLockTimestamp
)
)
}
if (readLockTimestamp != 0) {
logLockRelease(
logger,
"read compilation",
readLockTimestamp,
ctx.locking.releaseReadCompilationLock()
logger.log(
Level.FINEST,
"Kept read compilation lock [{0}] for {1} milliseconds",
Array(
getClass.getSimpleName,
System.currentTimeMillis - readLockTimestamp
)
)
}
}
}

View File

@ -1,9 +1,11 @@
package org.enso.interpreter.instrument.command
import com.oracle.truffle.api.TruffleLogger
import org.enso.interpreter.instrument.execution.{Completion, RuntimeContext}
import org.enso.polyglot.runtime.Runtime.{Api, ApiNotification, ApiResponse}
import org.enso.polyglot.runtime.Runtime.Api.RequestId
import java.util.logging.Level
import scala.concurrent.ExecutionContext
/** Base command trait that encapsulates a function request. Uses
@ -35,4 +37,24 @@ abstract class Command(maybeRequestId: Option[RequestId]) {
)(implicit ctx: RuntimeContext): Unit = {
ctx.endpoint.sendToClient(Api.Response(None, payload))
}
protected def logLockRelease(
logger: TruffleLogger,
name: String,
startTime: Long,
release: => Unit
): Unit = {
if (startTime != 0) {
release
logger.log(
Level.FINEST,
"Kept {0} lock [{1}] for {2} milliseconds",
Array(
name,
getClass.getSimpleName,
System.currentTimeMillis - startTime
)
)
}
}
}

View File

@ -46,17 +46,12 @@ class DestroyContextCmd(
case ie: InterruptedException =>
logger.log(Level.WARNING, "Failed to acquire lock: interrupted", ie)
} finally {
if (lockTimestamp != 0) {
logLockRelease(
logger,
"context",
lockTimestamp,
ctx.locking.removeContextLock(request.contextId)
logger.log(
Level.FINEST,
s"Kept context lock [{0}] for {1} milliseconds",
Array(
getClass.getSimpleName,
System.currentTimeMillis() - lockTimestamp
)
)
}
}
}

View File

@ -48,28 +48,18 @@ class EditFileCmd(request: Api.EditFileNotification)
logger.log(Level.WARNING, "Failed to acquire lock: interrupted", ie)
Future.failed(ie)
} finally {
if (pendingEditsLockTimestamp != 0) {
logLockRelease(
logger,
"pending edits",
pendingEditsLockTimestamp,
ctx.locking.releasePendingEditsLock()
logger.log(
Level.FINEST,
"Kept pending edits lock [{0}] for {1} milliseconds",
Array(
getClass.getSimpleName,
System.currentTimeMillis() - pendingEditsLockTimestamp
)
)
}
if (fileLockTimestamp != 0) {
logLockRelease(
logger,
"file",
fileLockTimestamp,
ctx.locking.releaseFileLock(request.path)
logger.log(
Level.FINEST,
"Kept file lock [{0}] for {1} milliseconds",
Array(
getClass.getSimpleName,
System.currentTimeMillis() - fileLockTimestamp
)
)
}
}
}

View File

@ -38,28 +38,18 @@ class OpenFileCmd(
case ie: InterruptedException =>
logger.log(Level.WARNING, "Failed to acquire lock: interrupted", ie)
} finally {
if (fileLockTimestamp != 0) {
logLockRelease(
logger,
"file",
fileLockTimestamp,
ctx.locking.releaseFileLock(request.path)
logger.log(
Level.FINEST,
"Kept file lock [{0}] for {1} milliseconds",
Array(
getClass.getSimpleName,
System.currentTimeMillis() - fileLockTimestamp
)
)
}
if (readLockTimestamp != 0) {
logLockRelease(
logger,
"read compilation",
readLockTimestamp,
ctx.locking.releaseReadCompilationLock()
logger.log(
Level.FINEST,
"Kept read compilation lock [{0}] for {1} milliseconds",
Array(
getClass.getSimpleName,
System.currentTimeMillis() - readLockTimestamp
)
)
}
}
}
}

View File

@ -114,17 +114,12 @@ class RenameProjectCmd(
)
reply(Api.ProjectRenameFailed(request.oldName, request.newName))
} finally {
if (writeLockTimestamp != 0) {
logLockRelease(
logger,
"write compilation",
writeLockTimestamp,
ctx.locking.releaseWriteCompilationLock()
logger.log(
Level.FINEST,
"Kept write compilation lock [{0}] for {1} milliseconds",
Array(
getClass.getSimpleName,
System.currentTimeMillis() - writeLockTimestamp
)
)
}
}
}

View File

@ -48,29 +48,18 @@ class SetExpressionValueCmd(request: Api.SetExpressionValueNotification)
logger.log(Level.WARNING, "Failed to acquire lock: interrupted", ie)
Future.failed(ie)
} finally {
if (pendingEditsLockTimestamp != 0) {
logLockRelease(
logger,
"pending edits",
pendingEditsLockTimestamp,
ctx.locking.releasePendingEditsLock()
logger.log(
Level.FINEST,
"Kept pending edits lock [{0}] for {1} milliseconds",
Array(
getClass.getSimpleName,
System.currentTimeMillis - pendingEditsLockTimestamp
)
)
}
if (fileLockTimestamp != 0) {
logLockRelease(
logger,
"file",
fileLockTimestamp,
ctx.locking.releaseFileLock(request.path)
logger.log(
Level.FINEST,
"Kept file lock [{0}] for {1} milliseconds",
Array(
getClass.getSimpleName,
System.currentTimeMillis - fileLockTimestamp
)
)
}
}
}

View File

@ -45,17 +45,12 @@ class DetachVisualizationJob(
case ie: InterruptedException =>
logger.log(Level.WARNING, "Failed to acquire lock: interrupted", ie)
} finally {
if (contextId != 0) {
logLockRelease(
logger,
"context",
lockTimestamp,
ctx.locking.releaseContextLock(contextId)
logger.log(
Level.FINEST,
s"Kept context lock [{0}] for {1} milliseconds",
Array(
getClass.getSimpleName,
System.currentTimeMillis() - lockTimestamp
)
)
}
}
}
}

View File

@ -63,17 +63,12 @@ final class EnsureCompiledJob(
logger.log(Level.WARNING, "Failed to acquire lock: interrupted", ie)
CompilationStatus.Failure
} finally {
if (writeLockTimestamp != 0) {
logLockRelease(
logger,
"write compilation",
writeLockTimestamp,
ctx.locking.releaseWriteCompilationLock()
logger.log(
Level.FINEST,
s"Kept write compilation lock [{0}] for {1} milliseconds",
Array(
getClass.getSimpleName,
System.currentTimeMillis() - writeLockTimestamp
)
)
}
}
}
@ -280,9 +275,11 @@ final class EnsureCompiledJob(
ctx: RuntimeContext,
logger: TruffleLogger
): Option[Changeset[Rope]] = {
val fileLockTimestamp = ctx.locking.acquireFileLock(file)
val pendingEditsLockTimestamp = ctx.locking.acquirePendingEditsLock()
var fileLockTimestamp: Long = 0
var pendingEditsLockTimestamp: Long = 0
try {
fileLockTimestamp = ctx.locking.acquireFileLock(file)
pendingEditsLockTimestamp = ctx.locking.acquirePendingEditsLock()
val pendingEdits = ctx.state.pendingEdits.dequeue(file)
val edits = pendingEdits.map(_.edit)
val shouldExecute =
@ -303,17 +300,18 @@ final class EnsureCompiledJob(
)
Option.when(shouldExecute)(changeset)
} finally {
logLockRelease(
logger,
"pending edits",
pendingEditsLockTimestamp,
ctx.locking.releasePendingEditsLock()
logger.log(
Level.FINEST,
s"Kept pending edits lock [EnsureCompiledJob] for ${System.currentTimeMillis() - pendingEditsLockTimestamp} milliseconds"
)
logLockRelease(
logger,
"file",
fileLockTimestamp,
ctx.locking.releaseFileLock(file)
logger.log(
Level.FINEST,
s"Kept file lock [EnsureCompiledJob] for ${System.currentTimeMillis() - fileLockTimestamp} milliseconds"
)
}
}

View File

@ -91,29 +91,18 @@ class ExecuteJob(
)
)
} finally {
if (readLockTimestamp != 0) {
logLockRelease(
logger,
"read compilation",
readLockTimestamp,
ctx.locking.releaseReadCompilationLock()
logger.log(
Level.FINEST,
s"Kept read compilation lock [{0}] for {1} milliseconds",
Array(
getClass.getSimpleName,
System.currentTimeMillis() - readLockTimestamp
)
)
}
if (contextLockTimestamp != 0) {
logLockRelease(
logger,
"context",
contextLockTimestamp,
ctx.locking.releaseContextLock(contextId)
logger.log(
Level.FINEST,
s"Kept context lock [{0}] for {1} for {2} milliseconds",
Array(
getClass.getSimpleName,
contextId,
System.currentTimeMillis() - contextLockTimestamp
)
)
}
}
}

View File

@ -1,9 +1,12 @@
package org.enso.interpreter.instrument.job
import java.util.UUID
import com.oracle.truffle.api.TruffleLogger
import java.util.UUID
import org.enso.interpreter.instrument.execution.RuntimeContext
import java.util.logging.Level
/** A fine-grained request for a runtime server service. Uses [[RuntimeContext]]
* to perform a request.
*
@ -23,6 +26,38 @@ abstract class Job[+A](
* @param ctx contains suppliers of services to perform a request
*/
def run(implicit ctx: RuntimeContext): A
protected def logLockRelease(
logger: TruffleLogger,
name: String,
startTime: Long,
release: => Unit
): Unit = {
Job.logLockRelease(logger, name, startTime, release)
}
}
object Job {
protected[job] def logLockRelease(
logger: TruffleLogger,
name: String,
startTime: Long,
release: => Unit
): Unit = {
if (startTime != 0) {
release
logger.log(
Level.FINEST,
"Kept {0} lock [{1}] for {2} milliseconds",
Array(
name,
getClass.getSimpleName,
System.currentTimeMillis - startTime
)
)
}
}
}
/** The job queue can contain only one job of this type decided by the

View File

@ -80,17 +80,12 @@ final class RefactoringRenameJob(
)
Seq()
} finally {
if (compilationLockTimestamp != 0) {
logLockRelease(
logger,
"read compilation",
compilationLockTimestamp,
ctx.locking.releaseReadCompilationLock()
logger.log(
Level.FINEST,
s"Kept read compilation lock [{0}] for {1} milliseconds.",
Array(
getClass.getSimpleName,
System.currentTimeMillis() - compilationLockTimestamp
)
)
}
}
}
@ -154,20 +149,18 @@ final class RefactoringRenameJob(
private def enqueuePendingEdits(fileEdit: Api.FileEdit)(implicit
ctx: RuntimeContext
): Unit = {
val pendingEditsLockTimestamp = ctx.locking.acquirePendingEditsLock()
var pendingEditsLockTimestamp: Long = 0
try {
pendingEditsLockTimestamp = ctx.locking.acquirePendingEditsLock()
val pendingEdits =
fileEdit.edits.map(PendingEdit.ApplyEdit(_, execute = true))
ctx.state.pendingEdits.enqueue(fileEdit.path, pendingEdits)
} finally {
ctx.locking.releasePendingEditsLock()
ctx.executionService.getLogger.log(
Level.FINEST,
s"Kept pending edits lock [{0}] for {1} milliseconds.",
Array(
getClass.getSimpleName,
System.currentTimeMillis() - pendingEditsLockTimestamp
)
logLockRelease(
ctx.executionService.getLogger,
"pending edits",
pendingEditsLockTimestamp,
ctx.locking.releaseReadCompilationLock()
)
}
}

View File

@ -113,17 +113,12 @@ class UpsertVisualizationJob(
logger.log(Level.WARNING, "Failed to acquire lock: interrupted", ie)
None
} finally {
if (lockTimestamp != 0) {
logLockRelease(
logger,
"context",
lockTimestamp,
ctx.locking.releaseContextLock(config.executionContextId)
logger.log(
Level.FINEST,
"Kept context lock [{0}] for {1} milliseconds.",
Array(
getClass.getSimpleName,
System.currentTimeMillis() - lockTimestamp
)
)
}
}
}
@ -488,14 +483,16 @@ object UpsertVisualizationJob {
callback,
arguments
)
val writeLockTimestamp = ctx.locking.acquireWriteCompilationLock()
var writeLockTimestamp: Long = 0
try {
writeLockTimestamp = ctx.locking.acquireWriteCompilationLock()
invalidateCaches(visualization)
} finally {
ctx.locking.releaseWriteCompilationLock()
logger.log(
Level.FINEST,
s"Kept write compilation lock [UpsertVisualizationJob] for ${System.currentTimeMillis() - writeLockTimestamp} milliseconds"
Job.logLockRelease(
logger,
"write compilation",
writeLockTimestamp,
ctx.locking.releaseReadCompilationLock()
)
}
ctx.contextManager.upsertVisualization(