Log slow RPC requests #8349
Log slow RPC requests #8349
Conversation
📝 WalkthroughWalkthroughThis pull request introduces a comprehensive refactoring of time handling and logging across multiple Scala files in the project. The primary focus is on replacing Changes
Poem
📜 Recent review detailsConfiguration used: CodeRabbit UI 📒 Files selected for processing (1)
✅ Files skipped from review due to trivial changes (1)
⏰ Context from checks skipped due to timeout of 90000ms (1)
Thank you for using CodeRabbit. We offer it for free to the OSS community and would appreciate your support in helping us grow. If you find it useful, would you consider giving us a shout-out on your favorite social media? 🪧 TipsChatThere are 3 ways to chat with CodeRabbit:
Note: Be mindful of the bot's finite context window. It's strongly recommended to break down tasks such as reading entire modules into smaller chunks. For a focused discussion, use review comments to chat about specific files and their changes, instead of using the PR comments. CodeRabbit Commands (Invoked using PR comments)
Other keywords and placeholders
CodeRabbit Configuration File (
|
![coderabbitai[bot]](https://avatars.githubusercontent.com/in/347564?s=60&v=4){kind=small}
There was a problem hiding this comment.
Actionable comments posted: 3
🔭 Outside diff range comments (1)
util/src/main/scala/com/scalableminds/util/requestlogging/RequestLogging.scala (1)
Line range hint
33-46: Consider adding support for the .silent flag.The PR objectives mention that slow RPC requests should not be logged if they have the
.silentflag set. However, this condition is not implemented in the current code.Consider adding the silent flag check:
def logTime(notifier: String => Unit, durationThreshold: FiniteDuration = 30 seconds)( block: => Future[Result])(implicit request: Request[_], ec: ExecutionContext): Future[Result] = { def logTimeFormatted(executionTime: FiniteDuration, request: Request[_], result: Result): Unit = { val debugString = s"Request ${request.method} ${request.uri} took ${formatDuration(executionTime)} and was${if (result.header.status != 200) " not " else " "}successful" logger.info(debugString) notifier(debugString) } val start = Instant.now for { result: Result <- block executionTime = Instant.since(start) - _ = if (executionTime > durationThreshold) logTimeFormatted(executionTime, request, result) + _ = if (executionTime > durationThreshold && !request.getQueryString("silent").contains("true")) { + logTimeFormatted(executionTime, request, result) + } } yield result }
🧹 Nitpick comments (14)
webknossos-tracingstore/app/com/scalableminds/webknossos/tracingstore/controllers/Application.scala (1)
30-31: Consider improving log message readability.The current string concatenation could be made more readable. Consider using a multi-line string interpolation:
- s"Answering ok for Tracingstore health check, took ${formatDuration(afterRedis - before)} (FossilDB at ${tracingDataStore.healthClient.authority} ${formatDuration(afterFossil - before)}, Redis at ${redisClient.authority} ${formatDuration(afterRedis - afterFossil)})." + s"""Answering ok for Tracingstore health check: + |Total time: ${formatDuration(afterRedis - before)} + |FossilDB at ${tracingDataStore.healthClient.authority}: ${formatDuration(afterFossil - before)} + |Redis at ${redisClient.authority}: ${formatDuration(afterRedis - afterFossil)}""".stripMarginwebknossos-datastore/app/com/scalableminds/webknossos/datastore/slacknotification/SlackClient.scala (1)
58-67: Consider extracting the time comparison for better readability.The rate limit logic is correctly updated to use Instant, maintaining the original behavior while improving type safety. However, the time comparison could be made more explicit.
Consider this minor improvement:
- if (currentTimestamp - lastResetTimestamp > rateLimitInterval) { + val timeSinceLastReset = currentTimestamp - lastResetTimestamp + if (timeSinceLastReset > rateLimitInterval) {webknossos-datastore/app/com/scalableminds/webknossos/datastore/services/MappingParser.scala (1)
56-56: Consider conditional logging based on duration.Since the PR's objective is to log slow operations (>2 minutes), consider using
logSinceLongRunningor adding a duration threshold check to avoid logging quick parsing operations.Example modification:
- Instant.logSince(before, s"JSON Mapping parsing", logger) + Instant.logSinceLongRunning(before, s"JSON Mapping parsing for ${nameOpt.getOrElse("unknown")}", logger)This would:
- Only log if the operation exceeds the threshold
- Include the mapping name in the log message for better context
webknossos-datastore/app/com/scalableminds/webknossos/datastore/storage/CumsumParser.scala (1)
69-69: Consider adding error duration logging.While the change to use
Instant.nowis good, consider capturing the duration even when parsing fails. This would help in debugging performance issues.def parse(f: File, maxReaderRange: Long): BoundingBoxCache = { + val before = Instant.now + try { - parseImpl(f, maxReaderRange, List(), Instant.now) + parseImpl(f, maxReaderRange, List(), before) + } catch { + case e: Exception => + Instant.logSince(before, s"Failed cumsum JSON parsing", logger) + throw e + } +}webknossos-datastore/app/com/scalableminds/webknossos/datastore/controllers/DataSourceController.scala (1)
485-491: LGTM! Consider extracting the duration threshold.The changes improve time tracking by using the more precise
Instantclass. The code is now more consistent with the codebase's time handling patterns.Consider extracting the
10 secondsthreshold to a named constant for better maintainability.+ private val StorageMeasurementLogThreshold = 10.seconds - if (Instant.since(before) > (10 seconds)) { + if (Instant.since(before) > StorageMeasurementLogThreshold) {webknossos-datastore/app/com/scalableminds/webknossos/datastore/rpc/RPCRequest.scala (1)
25-25: Consider adding documentation for the threshold configuration method.The threshold implementation looks good and matches the PR requirements. Consider adding ScalaDoc to document the purpose and usage of
withSlowRequestLoggingThreshold.+ /** Configures the duration threshold above which requests will be logged as slow. + * @param slowRequestLoggingThreshold The duration threshold + * @return This RPCRequest instance for method chaining + */ def withSlowRequestLoggingThreshold(slowRequestLoggingThreshold: FiniteDuration): RPCRequest = {Also applies to: 50-53
util/src/main/scala/com/scalableminds/util/mvc/Formatter.scala (2)
27-77: Simplify and enhance the readability of duration formatting logicThe current implementation of
formatDurationis complex and can be hard to maintain. Consider simplifying the logic and using well-known libraries or utilities for duration formatting.For example, you could use
java.time.Durationand its built-in formatting methods:import java.time.Duration protected def formatDuration(duration: FiniteDuration): String = { val javaDuration = Duration.ofMillis(duration.toMillis) val days = javaDuration.toDaysPart() val hours = javaDuration.toHoursPart() val minutes = javaDuration.toMinutesPart() val seconds = javaDuration.toSecondsPart() val millis = javaDuration.toMillisPart() val parts = List( if (days > 0) s"${days}d" else "", if (hours > 0) s"${hours}h" else "", if (minutes > 0) s"${minutes}m" else "", if (seconds > 0) s"${seconds}s" else "", if (millis > 0 && days == 0) s"${millis}ms" else "" ).filterNot(_.isEmpty) if (parts.nonEmpty) parts.mkString(" ") else "0ms" }This refactor improves readability and leverages the robust
java.timeAPI.
27-77: Define constants for time units to enhance clarityThe code uses hardcoded numerical values for time conversions (e.g.,
24 * 3600 * 1000). Defining constants can improve readability:val MillisPerSecond = 1000 val MillisPerMinute = MillisPerSecond * 60 val MillisPerHour = MillisPerMinute * 60 val MillisPerDay = MillisPerHour * 24 // Use these constants in calculationswebknossos-datastore/app/com/scalableminds/webknossos/datastore/controllers/Application.scala (1)
27-28: Optimized logging to avoid redundant calculationsIn the logging statement,
formatDuration(afterRedis - before)is computed twice. Consider storing it in a variable to enhance efficiency:afterRedis = Instant.now + val duration = afterRedis - before _ <- Fox.bool2Fox(applicationHealthService.getRecentProblem().isEmpty) ?~> "Java Internal Errors detected" _ = logger.info( - s"Answering ok for Datastore health check, took ${formatDuration(afterRedis - before)} (Redis at ${redisClient.authority} ${formatDuration( - afterRedis - before)})") + s"Answering ok for Datastore health check, took ${formatDuration(duration)} (Redis at ${redisClient.authority} ${formatDuration(duration)})")util/src/main/scala/com/scalableminds/util/tools/TextUtils.scala (1)
73-74: Consider using a more comprehensive pluralization solution.While the current implementation handles basic pluralization, it might be too simplistic for all use cases. Consider:
- Irregular plurals (e.g., "child" → "children")
- Words ending in 'y' (e.g., "story" → "stories")
- Words ending in 's', 'x', 'z', 'ch', 'sh' (e.g., "box" → "boxes")
-def pluralize(string: String, amount: Int): String = - if (amount == 1) string else s"${string}s" +def pluralize(string: String, amount: Int): String = { + if (amount == 1) return string + // Handle irregular plurals + val irregulars = Map( + "child" -> "children", + "person" -> "people", + // Add more as needed + ) + irregulars.get(string).getOrElse { + string match { + case s if s.endsWith("y") && !s.endsWith("ay|ey|iy|oy|uy") => + s"${string.dropRight(1)}ies" + case s if s.matches(".*(s|x|z|ch|sh)$") => + s"${string}es" + case _ => + s"${string}s" + } + } +}test/backend/FormatterTestSuite.scala (1)
8-51: Add more edge cases to strengthen test coverage.The test suite is comprehensive but could benefit from additional test cases:
- Zero duration with different units (e.g., 0s, 0m, 0h)
- Boundary cases for rounding (e.g., 1.999s → 2s)
- Maximum duration handling
Add these test cases:
assert(formatDuration(FiniteDuration(0, "ms")) == "0ms") +assert(formatDuration(FiniteDuration(0, "s")) == "0s") +assert(formatDuration(FiniteDuration(0, "m")) == "0m") +assert(formatDuration(FiniteDuration(0, "h")) == "0h") + +// Boundary cases for rounding +assert(formatDuration(FiniteDuration(1999, "ms")) == "2s") +assert(formatDuration(FiniteDuration(59999, "ms")) == "1m") + +// Maximum duration handling +assert(formatDuration(FiniteDuration(Long.MaxValue, "ms")) == "...")app/models/job/Worker.scala (1)
138-138: Consider formatting timestamps in logs for better readability.While using
Instant.toStringdirectly works, consider using a more human-readable format for log messages.- s"Worker ${worker.name} (${worker._id}) is not reporting. Last heartbeat was at ${worker.lastHeartBeat}" + s"Worker ${worker.name} (${worker._id}) is not reporting. Last heartbeat was at ${formatDate(worker.lastHeartBeat)}"Also applies to: 145-145
app/models/voxelytics/LokiClient.scala (1)
207-207: Improved error handling for timestamp parsing.The addition of
toFoxenhances error handling by properly propagating potential failures during timestamp parsing.Consider adding error logging to help diagnose timestamp parsing failures in production:
- Instant.fromString(timestampString).toFox + Instant.fromString(timestampString).toFox.tapError(e => + logger.warn(s"Failed to parse timestamp: $timestampString", e))util/src/main/scala/com/scalableminds/util/tools/ConfigReader.scala (1)
8-14: Document the expected time string format.Add scaladoc to document the expected format for time strings in the configuration to help users provide correct values.
implicit val instantConfigLoader: ConfigLoader[Instant] = new ConfigLoader[Instant] { + /** Loads an Instant from configuration. + * @param rootConfig The configuration object + * @param path The configuration path + * @return The parsed Instant + * @throws IllegalArgumentException if the time string format is invalid + * Expected format: ISO-8601 timestamp (e.g., "2024-01-15T10:15:30Z") + */ def load(rootConfig: Config, path: String): Instant = {
📜 Review details
Configuration used: CodeRabbit UI
Review profile: CHILL
Plan: Pro
📒 Files selected for processing (29)
app/Startup.scala(3 hunks)app/controllers/DatasetController.scala(2 hunks)app/controllers/OrganizationController.scala(1 hunks)app/files/TempFileService.scala(3 hunks)app/models/analytics/AnalyticsService.scala(2 hunks)app/models/annotation/AnnotationStore.scala(0 hunks)app/models/job/Worker.scala(4 hunks)app/models/voxelytics/LokiClient.scala(1 hunks)app/utils/WkConf.scala(1 hunks)test/backend/FormatterTestSuite.scala(1 hunks)test/backend/InstantTestSuite.scala(1 hunks)util/src/main/scala/com/scalableminds/util/mvc/ExtendedController.scala(2 hunks)util/src/main/scala/com/scalableminds/util/mvc/Formatter.scala(1 hunks)util/src/main/scala/com/scalableminds/util/requestlogging/RequestLogging.scala(3 hunks)util/src/main/scala/com/scalableminds/util/time/Instant.scala(4 hunks)util/src/main/scala/com/scalableminds/util/tools/ConfigReader.scala(1 hunks)util/src/main/scala/com/scalableminds/util/tools/TextUtils.scala(1 hunks)webknossos-datastore/app/com/scalableminds/webknossos/datastore/controllers/Application.scala(2 hunks)webknossos-datastore/app/com/scalableminds/webknossos/datastore/controllers/BinaryDataController.scala(2 hunks)webknossos-datastore/app/com/scalableminds/webknossos/datastore/controllers/DataSourceController.scala(2 hunks)webknossos-datastore/app/com/scalableminds/webknossos/datastore/rpc/RPCRequest.scala(5 hunks)webknossos-datastore/app/com/scalableminds/webknossos/datastore/services/AgglomerateService.scala(4 hunks)webknossos-datastore/app/com/scalableminds/webknossos/datastore/services/FullMeshHelper.scala(1 hunks)webknossos-datastore/app/com/scalableminds/webknossos/datastore/services/MappingParser.scala(3 hunks)webknossos-datastore/app/com/scalableminds/webknossos/datastore/slacknotification/SlackClient.scala(3 hunks)webknossos-datastore/app/com/scalableminds/webknossos/datastore/storage/CumsumParser.scala(4 hunks)webknossos-tracingstore/app/com/scalableminds/webknossos/tracingstore/controllers/Application.scala(2 hunks)webknossos-tracingstore/app/com/scalableminds/webknossos/tracingstore/tracings/editablemapping/EditableMappingService.scala(1 hunks)webknossos-tracingstore/app/com/scalableminds/webknossos/tracingstore/tracings/volume/VolumeTracingService.scala(3 hunks)
💤 Files with no reviewable changes (1)
- app/models/annotation/AnnotationStore.scala
✅ Files skipped from review due to trivial changes (3)
- webknossos-tracingstore/app/com/scalableminds/webknossos/tracingstore/tracings/editablemapping/EditableMappingService.scala
- app/controllers/DatasetController.scala
- webknossos-tracingstore/app/com/scalableminds/webknossos/tracingstore/tracings/volume/VolumeTracingService.scala
⏰ Context from checks skipped due to timeout of 90000ms (1)
- GitHub Check: circleci_build
🔇 Additional comments (42)
webknossos-tracingstore/app/com/scalableminds/webknossos/tracingstore/controllers/Application.scala (2)
3-4: LGTM! Clean trait integration for standardized formatting.The addition of the Formatter trait and related imports aligns well with the PR's objective of unifying duration formatting across the codebase.
Also applies to: 16-17
24-28: LGTM! Clean timing implementation.The use of
Instantfor timing operations is consistent with the PR objectives and provides precise timing for both FossilDB and Redis health checks.webknossos-datastore/app/com/scalableminds/webknossos/datastore/services/AgglomerateService.scala (1)
6-6: LGTM! Import changes align with standardized time handling.The addition of
InstantandDurationIntimports supports the PR's objective of unifying duration formatting and improving time precision.Also applies to: 25-25
webknossos-datastore/app/com/scalableminds/webknossos/datastore/slacknotification/SlackClient.scala (3)
3-3: LGTM! Import change aligns with standardization effort.The addition of the custom Instant import supports the PR's objective of standardizing time handling across the codebase.
12-13: LGTM! Improved naming convention compliance.The renaming of constants from uppercase to lowercase follows Scala's recommended naming conventions for private lazy vals.
16-16: LGTM! Enhanced type safety with Instant.The change from Long to Instant improves type safety and semantic clarity. Using Instant.zero as the initial value is more meaningful than a raw 0L.
webknossos-datastore/app/com/scalableminds/webknossos/datastore/services/MappingParser.scala (2)
7-7: LGTM!The import of the custom time utility is appropriately placed and necessary for the time tracking improvements.
37-37: LGTM!The initialization of time tracking using
Instant.nowis well-placed and follows the standardized approach for time handling.webknossos-datastore/app/com/scalableminds/webknossos/datastore/storage/CumsumParser.scala (3)
5-5: LGTM!The addition of the
Instantimport aligns with the PR's objective to improve time tracking.
21-21: LGTM!The parameter type change from
LongtoInstantand rename fromstarttobeforeimproves code clarity and aligns with the PR's objective to standardize time tracking.
52-54: LGTM!The changes maintain correct timing context in the recursive call and standardize duration logging using
Instant.logSince.webknossos-datastore/app/com/scalableminds/webknossos/datastore/controllers/DataSourceController.scala (1)
5-5: LGTM!The import for the
Instantclass is correctly placed and necessary for the time tracking changes.util/src/main/scala/com/scalableminds/util/requestlogging/RequestLogging.scala (2)
33-39: Consider adjusting the default duration threshold.The PR objective specifies logging slow RPC requests that exceed 2 minutes, but the default threshold is set to 30 seconds. While this lower threshold provides more verbose logging, it might not align with the intended use case.
Consider either:
- Increasing the default threshold to 2 minutes:
- def logTime(notifier: String => Unit, durationThreshold: FiniteDuration = 30 seconds)( + def logTime(notifier: String => Unit, durationThreshold: FiniteDuration = 2 minutes)(
- Or verify if this is intentionally kept lower for general-purpose logging:
Also applies to: 42-46
3-3: LGTM! Verify Formatter trait implementation.The addition of the Formatter trait and Instant utilities aligns well with the PR's objective of unifying duration formatting across the codebase.
Let's verify the Formatter trait implementation:
Also applies to: 12-12
✅ Verification successful
Verified: Formatter trait is properly implemented
The Formatter trait includes a comprehensive formatDuration method that handles all duration ranges appropriately, from milliseconds to days, with proper formatting and pluralization. The implementation aligns well with the PR's objective of unifying duration formatting.
🏁 Scripts executed
The following scripts were executed for the analysis:
Script:
#!/bin/bash # Check the Formatter trait implementation ast-grep --pattern 'trait Formatter { $$$ def formatDuration($_): $_ $$$ }'Length of output: 83
Script:
#!/bin/bash # First, find files containing Formatter trait definition rg -l "trait Formatter" # Then show the content of files containing Formatter rg -A 10 "trait Formatter"Length of output: 1168
Script:
#!/bin/bash # Get complete Formatter trait implementation cat util/src/main/scala/com/scalableminds/util/mvc/Formatter.scalaLength of output: 2700
webknossos-datastore/app/com/scalableminds/webknossos/datastore/rpc/RPCRequest.scala (6)
3-3: LGTM! Clean import additions and trait extension.The addition of Formatter trait and time-related imports aligns well with the PR's objective to improve logging of slow RPC requests.
Also applies to: 10-10, 20-20
198-198: Well-implemented timing and logging logic.The implementation correctly tracks request duration and logs slow requests as specified. The error messages are comprehensive and include relevant timing information.
Also applies to: 205-206, 208-208, 211-221
235-239: LGTM! Consistent logging implementation across response handlers.The logging implementation is consistent across different response types and provides appropriate level of detail for debugging.
Also applies to: 244-245, 259-260
272-272: LGTM! Well-structured debug information.The
debugInfomethod provides a consistent format for request identification, which improves log readability.
281-281: LGTM! Consistent byte length reporting.The byte length reporting is consistent with other binary data handling in the class.
198-221: Verify the implementation meets all requirements.Let's confirm the implementation handles all edge cases correctly:
- Logs requests exceeding 2 minutes
- Respects the
.silentflag- Provides formatted durations
- Handles errors appropriately
✅ Verification successful
Implementation verified and meets all requirements
The code correctly implements:
- Slow request logging with 2-minute threshold
- Proper verbose flag handling
- Duration formatting in all log messages
- Comprehensive error handling with duration information
🏁 Scripts executed
The following scripts were executed for the analysis:
Script:
#!/bin/bash # Description: Verify the logging implementation handles all cases correctly # Test 1: Search for duration threshold configuration echo "Checking duration threshold configuration..." rg -l "slowRequestLoggingThreshold.*2.minutes" --type scala # Test 2: Verify silent flag handling echo "Checking silent flag handling..." rg -l "verbose.*&&.*duration.*>.*slowRequestLoggingThreshold" --type scala # Test 3: Check duration formatting echo "Checking duration formatting..." rg -l "formatDuration.*duration" --type scala # Test 4: Verify error handling with duration echo "Checking error handling with duration..." rg -l "Duration:.*formatDuration.*duration" --type scalaLength of output: 1089
Script:
#!/bin/bash # Get detailed implementation of key components echo "=== Duration Threshold Configuration ===" rg "slowRequestLoggingThreshold.*2.minutes" -A 2 --type scala echo -e "\n=== Verbose Flag Implementation ===" rg "val.*verbose.*=" -A 2 --type scala echo -e "\n=== Duration Formatting Implementation ===" ast-grep --pattern 'def formatDuration($_) { $$$ }'Length of output: 2580
Script:
#!/bin/bash # Check duration formatting implementation and usage echo "=== Duration Formatting Method ===" rg "def formatDuration" -A 5 --type scala echo -e "\n=== Duration Usage in RPCRequest ===" rg "duration.*>.*slowRequestLoggingThreshold" -A 3 --type scala echo -e "\n=== Logging Implementation ===" rg "logger\.(debug|info|error)" -A 2 webknossos-datastore/app/com/scalableminds/webknossos/datastore/rpc/RPCRequest.scalaLength of output: 2711
util/src/main/scala/com/scalableminds/util/mvc/Formatter.scala (3)
3-4: Appropriate imports addedThe imports for
TextUtilsandFiniteDurationare necessary for the updated functionality in theformatDurationmethod.
7-8: Added import forListBufferImporting
scala.collection.mutable.ListBufferis required for constructing thelabelElementslist in theformatDurationmethod.
11-24: Changed method visibility may impact external usageThe methods
formatDate,formatDateForFilename, andformatHashhave been changed from public to protected. This alteration restricts access to these methods outside the class hierarchy.Please ensure that no external classes or objects rely on these methods. If they are used externally, consider keeping them public or providing alternative access.
test/backend/InstantTestSuite.scala (1)
14-15: Simplified parsing assertionsThe test assertions have been simplified by removing unnecessary asynchronous handling, which enhances readability.
webknossos-datastore/app/com/scalableminds/webknossos/datastore/controllers/Application.scala (2)
3-3: ImportedInstantfor time measurementThe import of
com.scalableminds.util.time.Instantallows for precise time measurements using the updatedInstantclass.
22-28: Updated health check timing withInstantThe timing mechanism in the
healthmethod now usesInstant.nowFoxandInstant.now, improving precision and consistency in time measurements.app/files/TempFileService.scala (3)
26-26: LGTM! Good use of Instant for improved time precision.The change from
LongtoInstantfor tracking expiry times enhances code readability and time precision.
38-38: LGTM! Consistent use of Instant for time calculations.The change to use
Instant.now + lifeTimealigns with the codebase's move towards using the Instant class for time operations.
Line range hint
42-51: LGTM! Appropriate visibility modifier and time comparison.Making cleanUpExpiredFiles private and using Instant for time comparison is a good practice. The method is correctly scoped as it's only used internally.
webknossos-datastore/app/com/scalableminds/webknossos/datastore/services/FullMeshHelper.scala (1)
74-74: LGTM! Consistent logging format.The change to use
Instant.logSincealigns with the PR's objective of unifying duration formatting across the codebase.util/src/main/scala/com/scalableminds/util/time/Instant.scala (2)
72-73: LGTM! Enhanced logging flexibility.The addition of a custom logger parameter with a default value maintains backward compatibility while allowing for more flexible logging configurations.
75-75: Verify error handling in the fromString method.The synchronous parsing of instant literals improves code simplicity, but we should ensure proper error handling for invalid inputs.
Run this script to check error handling:
Also applies to: 93-97
✅ Verification successful
Error handling is properly implemented ✅
The
fromStringmethod implements robust error handling through:
- Return type
Option[Instant]for safe failure handling- Exception-safe parsing using
tryo().toOption- Fallback parsing strategy with
orElse🏁 Scripts executed
The following scripts were executed for the analysis:
Script:
#!/bin/bash # Description: Check error handling for invalid instant literals ast-grep --pattern 'fromString($instantLiteral: String): Option[Instant]' -A 10Length of output: 81
Script:
#!/bin/bash # Get the implementation of fromString method rg "def fromString.*Option\[Instant\]" util/src/main/scala/com/scalableminds/util/time/Instant.scala -A 10 # Look for test files fd "Instant.*Test.*scala" --type f # If test file exists, check test cases rg "fromString.*invalid|malformed|error" -lLength of output: 21727
app/models/analytics/AnalyticsService.scala (1)
104-105: LGTM! Improved timestamp handling.The migration from
LongtoInstantenhances type safety and readability. The synchronization block correctly handles concurrent access to the session store.Also applies to: 108-111
app/Startup.scala (1)
39-39: LGTM! Enhanced startup time tracking.The migration to
Instantfor startup time tracking provides more precise measurements and consistent logging format.Also applies to: 93-93, 96-96
app/models/job/Worker.scala (2)
31-32: LGTM! Enhanced timestamp handling in Worker class.The migration from
LongtoInstantforlastHeartBeatandcreatedfields improves type safety and readability.
85-85: Improved heartbeat check logic.The use of
Instant.sincesimplifies the code and makes the duration comparison more intuitive.util/src/main/scala/com/scalableminds/util/mvc/ExtendedController.scala (2)
4-4: LGTM!The import of
Instantfrom the custom time utility package aligns with the PR's objective to standardize time handling across the codebase.
50-50: LGTM!The change from
System.currentTimeMillis()toInstant.nowimproves time precision and consistency in the error message formatting.app/utils/WkConf.scala (1)
3-3: LGTM!The import of
Instantfrom the custom time utility package aligns with the PR's objective to standardize time handling across the codebase.app/controllers/OrganizationController.scala (1)
134-135: LGTM!The changes simplify the code by:
- Directly using the
Instantobject in the response- Using the
isPastmethod for deadline checks instead of timestamp comparisonswebknossos-datastore/app/com/scalableminds/webknossos/datastore/controllers/BinaryDataController.scala (2)
70-70: LGTM! Duration formatting enhances log readability.The change aligns with the PR's objective of unifying duration formatting across the codebase.
69-70: Verify the slow request threshold.The PR objective specifies logging requests that exceed 2 minutes, but this code logs requests exceeding 10 seconds. Consider aligning the threshold with the PR objective or documenting why a different threshold is used here.
...ossos-datastore/app/com/scalableminds/webknossos/datastore/services/AgglomerateService.scala
Show resolved
Hide resolved
util/src/main/scala/com/scalableminds/util/tools/ConfigReader.scala
Outdated
Show resolved
Hide resolved
There was a problem hiding this comment.
Actionable comments posted: 0
♻️ Duplicate comments (1)
util/src/main/scala/com/scalableminds/util/tools/ConfigReader.scala (1)
15-15:⚠️ Potential issueRemove unsafe .get call on Option result.
Using
.geton theInstant.fromStringresult is unsafe and contradicts the purpose of the try-catch block. This is a potential source ofNoSuchElementExceptionthat bypasses yourNonFatalerror handling.Apply this fix:
- Instant.fromString(literal).get + Instant.fromString(literal).getOrElse { + throw new IllegalArgumentException(s"Invalid time format in configuration at path '$path': $literal") + }
🧹 Nitpick comments (2)
util/src/main/scala/com/scalableminds/util/mvc/Formatter.scala (2)
33-33: Document magic numbers.The magic numbers (59995, 59499) are used for rounding thresholds but their purpose isn't immediately clear. Consider extracting them as named constants with explanatory comments.
+ // Threshold for rounding up to the next unit (e.g., 59.995 seconds rounds to 1 minute) + private val RoundingThreshold = 59995 + // Threshold for displaying decimals (59.499 seconds) + private val DecimalThreshold = 59499 - else if (millisAbs < 59995) { + else if (millisAbs < RoundingThreshold) {Also applies to: 43-43, 53-53, 62-62
40-73: Consider simplifying the duration formatting logic.The current implementation uses mutable state and complex nested conditions. Consider refactoring to a more functional approach using pattern matching or case classes.
Here's a suggested approach:
case class TimeComponents(days: Long, hours: Long, minutes: Long, seconds: Long) protected def formatDuration(duration: FiniteDuration): String = { val sign = if (duration.toMillis < 0) "-" else "" val millis = Math.abs(duration.toMillis) if (millis < 1000) return s"$sign${millis}ms" if (millis < RoundingThreshold) return formatSeconds(sign, millis) val components = extractTimeComponents(millis) val labels = formatTimeComponents(components) sign + labels.mkString(" ") } private def extractTimeComponents(millis: Long): TimeComponents = { val days = millis / (24 * 3600 * 1000) val remainingAfterDays = millis % (24 * 3600 * 1000) val hours = remainingAfterDays / (3600 * 1000) val remainingAfterHours = remainingAfterDays % (3600 * 1000) val minutes = remainingAfterHours / (60 * 1000) val seconds = (remainingAfterHours % (60 * 1000)) / 1000 TimeComponents(days, hours, minutes, seconds) } private def formatTimeComponents(components: TimeComponents): List[String] = { val TimeComponents(days, hours, minutes, seconds) = components val labels = ListBuffer[String]() if (days > 0) labels += TextUtils.pluralize(s"$days day", days.toInt) if (hours > 0) labels += s"${hours}h" if (minutes > 0) labels += s"${minutes}m" if (days == 0 && seconds > 0) labels += s"${seconds}s" labels.toList }This approach:
- Eliminates mutable state
- Makes the logic more testable
- Improves readability
- Separates concerns
📜 Review details
Configuration used: CodeRabbit UI
Review profile: CHILL
Plan: Pro
📒 Files selected for processing (2)
util/src/main/scala/com/scalableminds/util/mvc/Formatter.scala(1 hunks)util/src/main/scala/com/scalableminds/util/tools/ConfigReader.scala(1 hunks)
⏰ Context from checks skipped due to timeout of 90000ms (1)
- GitHub Check: circleci_build
🔇 Additional comments (6)
util/src/main/scala/com/scalableminds/util/tools/ConfigReader.scala (2)
3-3: LGTM! Well-organized imports.The addition of
InstantandNonFatalimports supports the enhanced time handling and error management.Also applies to: 7-7
18-19: LGTM! Clear and helpful error message.The error message is well-formatted and provides clear guidance by including both the invalid value and an example of the expected format.
util/src/main/scala/com/scalableminds/util/mvc/Formatter.scala (4)
3-8: LGTM! Good choice of imports.The switch to
FiniteDurationis a better choice as it prevents infinite durations, and the addition ofTextUtilssupports proper pluralization.
11-25: LGTM! Good encapsulation.Making these utility methods protected improves encapsulation and prevents unintended usage from outside the trait.
28-29: LGTM! Proper handling of negative durations.The sign handling is clean and straightforward.
31-38: LGTM! Fixed precision issues.Good job addressing the previous review comment by using
toDoubleinstead oftoFloatfor better precision in calculations.
| // now drop the decimals from the right if they are zeroes. | ||
| f"$sign${withTwoDecimals.reverse.dropWhile(_ == '0').dropWhile(_ == '.').reverse}s" |
There was a problem hiding this comment.
Cant this be expressed a little easier?
- if centis == 0: only write
f"$sign$wholeSeconds" - if centis % 10 == 0: write
f"$sign$wholeSeconds.${centis / 10}" - else write
f"$sign$wholeSeconds.$centis%02d"
Using string operations to remove the trailing 0 or . seems a little too much maybe (feel free to argue)
| } | ||
|
|
||
| var minutes = Math.floor(millisAbs.toDouble / 60 / 1000).toLong | ||
| if (millisAbs - minutes * 60 * 1000 > 59499) { // extra minute to avoid 60s |
There was a problem hiding this comment.
As 59499 is used quite often I'd say to make this a constant val somewhere here to give it a name as it is not as intuitive as the other value (which are very common regarding time (span) calculations)
webknossos-datastore/app/com/scalableminds/webknossos/datastore/rpc/RPCRequest.scala
Show resolved
Hide resolved
There was a problem hiding this comment.
Actionable comments posted: 0
🧹 Nitpick comments (1)
util/src/main/scala/com/scalableminds/util/tools/ConfigReader.scala (1)
13-14: Enhance error message readability.Consider using backticks and consistent quoting in the error message for better readability in logs.
- s"Cannot read config value "$literal" for $path as Instant. Expected ISO date like "2023-01-01T00:00:00Z"") + s"Cannot read config value `$literal` for '$path' as Instant. Expected ISO date like '2023-01-01T00:00:00Z'")
📜 Review details
Configuration used: CodeRabbit UI
Review profile: CHILL
Plan: Pro
📒 Files selected for processing (2)
app/utils/WkConf.scala(1 hunks)util/src/main/scala/com/scalableminds/util/tools/ConfigReader.scala(1 hunks)
🚧 Files skipped from review as they are similar to previous changes (1)
- app/utils/WkConf.scala
⏰ Context from checks skipped due to timeout of 90000ms (1)
- GitHub Check: circleci_build
🔇 Additional comments (1)
util/src/main/scala/com/scalableminds/util/tools/ConfigReader.scala (1)
10-15: LGTM! Robust error handling implementation.The implementation properly handles invalid time strings and provides clear error messages. The use of
getOrElsewithIllegalArgumentExceptionis a good practice for configuration validation.
There was a problem hiding this comment.
Actionable comments posted: 0
🧹 Nitpick comments (2)
util/src/main/scala/com/scalableminds/util/mvc/Formatter.scala (2)
44-47: Consider extracting rounding logic to a helper method.The rounding logic is repeated for days, hours, and minutes with similar patterns. This could be extracted to reduce duplication.
trait Formatter { + private def shouldRoundUp(remaining: Long, threshold: Long): Boolean = + remaining > threshold + protected def formatDuration(duration: FiniteDuration): String = { // ... var days = Math.floor(millisAbs.toDouble / 1000 / 3600 / 24).toLong - if (millisAbs - days * 24 * 3600 * 1000 > 23 * 3600 * 1000 + 59 * 60 * 1000 + minuteRoundingThresholdMillisForRenderingSeconds) { + if (shouldRoundUp(millisAbs - days * 24 * 3600 * 1000, 23 * 3600 * 1000 + 59 * 60 * 1000 + minuteRoundingThresholdMillisForRenderingSeconds)) { days += 1 } // Similar changes for hours and minutesAlso applies to: 54-57, 63-66
72-75: Consider consistent unit suffix handling.While other units use single-letter suffixes (h, m), seconds uses 's'. Consider standardizing the suffix style.
- labelElements += s"${seconds}s" + labelElements += s"${seconds}s" // Keep as is, since "s" is more readable than single-letter
📜 Review details
Configuration used: CodeRabbit UI
Review profile: CHILL
Plan: Pro
📒 Files selected for processing (2)
test/backend/FormatterTestSuite.scala(1 hunks)util/src/main/scala/com/scalableminds/util/mvc/Formatter.scala(1 hunks)
🚧 Files skipped from review as they are similar to previous changes (1)
- test/backend/FormatterTestSuite.scala
🔇 Additional comments (6)
util/src/main/scala/com/scalableminds/util/mvc/Formatter.scala (6)
3-8: LGTM! Import changes align with the new implementation.The new imports support the enhanced duration formatting functionality with proper pluralization and mutable collections.
27-27: Good change to FiniteDuration for parameter type.Using
FiniteDurationinstead ofDurationprevents potential issues with infinite durations and makes the API contract clearer.
28-29: Extract threshold values as named constants.The threshold values would be clearer with descriptive names at the trait level.
trait Formatter { + private val MinuteRoundingThresholdForMillis = 59995 // ~1 minute in milliseconds + private val MinuteRoundingThresholdForSeconds = 59499 // ~1 minute in milliseconds for second precision + protected def formatDuration(duration: FiniteDuration): String = { - val minuteRoundingThresholdMillisForRenderingMillis = 59995 - val minuteRoundingThresholdMillisForRenderingSeconds = 59499
33-40: Improved handling of decimal places in seconds.The implementation now properly handles different cases for decimal places, addressing the previous review comment about string manipulation. The code is more readable and maintainable.
11-25: Verify the impact of changing method visibility to protected.The change from public to protected access for these formatting methods could break external code that directly uses these utilities.
Let's verify the usage of these methods across the codebase:
✅ Verification successful
Method visibility changes are safe ✅
The change to protected visibility is safe as all usages of these formatting methods are through classes that extend the Formatter trait, where protected members remain accessible.
🏁 Scripts executed
The following scripts were executed for the analysis:
Script:
#!/bin/bash # Search for direct usage of these formatting methods echo "Searching for direct method calls..." rg -A 2 "formatDate|formatDateForFilename|formatHash" --type scala # Search for classes extending Formatter trait echo "Searching for Formatter trait usage..." rg -A 2 "extends.*Formatter" --type scalaLength of output: 3985
27-79: Verify duration formatting for slow RPC requests.The implementation aligns with the PR objective of logging slow RPC requests (>2 minutes). Let's verify the formatting for such durations:
✅ Verification successful
Duration formatting for slow RPC requests is implemented correctly
The implementation properly formats durations around the 2-minute threshold with appropriate rounding behavior:
- Exactly 2 minutes: "2m"
- 2 minutes 1 second: "2m 1s"
- 2 minutes 59.5 seconds: rounds up to "3m"
🏁 Scripts executed
The following scripts were executed for the analysis:
Script:
#!/bin/bash # Create a test file to verify duration formatting cat << 'EOF' > /tmp/DurationTest.scala import scala.concurrent.duration._ import com.scalableminds.util.mvc.Formatter object DurationTest extends Formatter { def main(args: Array[String]): Unit = { val twoMinutes = 2.minutes val twoMinutesAndOneSecond = 121.seconds println(s"2 minutes: ${formatDuration(twoMinutes)}") println(s"2 minutes 1 second: ${formatDuration(twoMinutesAndOneSecond)}") } } EOF # Compile and run the test scalac /tmp/DurationTest.scala && scala DurationTestLength of output: 136
Script:
#!/bin/bash # Create a Python script to verify duration formatting logic cat << 'EOF' > /tmp/test_duration.py def format_duration_ms(millis): minute_threshold_ms = 59499 # from the Scala code sign = "-" if millis < 0 else "" millis_abs = abs(millis) # We're only interested in the minutes/hours formatting for RPC timing minutes = int(millis_abs / (60 * 1000)) remaining_ms = millis_abs - (minutes * 60 * 1000) if remaining_ms > minute_threshold_ms: minutes += 1 remaining_ms = 0 parts = [] if minutes > 0: parts.append(f"{minutes}m") if remaining_ms > 0: seconds = round(remaining_ms / 1000) if seconds > 0: parts.append(f"{seconds}s") return sign + " ".join(parts) # Test cases test_cases = [ (120000, "2m"), # Exactly 2 minutes (121000, "2m 1s"), # 2 minutes 1 second (119000, "1m 59s"), # 1 minute 59 seconds (179000, "2m 59s"), # 2 minutes 59 seconds (179500, "3m"), # 2 minutes 59.5 seconds (should round up) ] print("Testing duration formatting:") for ms, expected in test_cases: result = format_duration_ms(ms) print(f"{ms}ms -> '{result}' (expected: '{expected}')") EOF python3 /tmp/test_duration.pyLength of output: 258
.silent).URL of deployed dev instance (used for testing):
Steps to test: