feat(logging): add option to log slow GraphQL queries #11308
Conversation
WalkthroughThe changes introduce enhancements to the Changes
Poem
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 (
|
github-actions
bot
added
product
|
@coderabbitai review |
Actions performedReview triggered.
|
![coderabbitai[bot]](https://avatars.githubusercontent.com/in/347564?s=60&v=4){kind=small}
There was a problem hiding this comment.
Actionable comments posted: 2
Review details
Configuration used: CodeRabbit UI
Review profile: CHILL
Files selected for processing (2)
- datahub-frontend/app/controllers/Application.java (5 hunks)
- datahub-frontend/conf/application.conf (1 hunks)
Additional comments not posted (5)
datahub-frontend/conf/application.conf (2)
303-307: Review of New GraphQL Logging ConfigurationThe new settings introduced for logging slow GraphQL queries (
graphql.verbose.loggingandgraphql.verbose.slowQueryMillis) are well-defined and follow the existing configuration pattern. These settings allow for toggling verbose logging and defining a threshold for what constitutes a slow query, which aligns with the PR's objectives to enhance performance monitoring.
- Correctness: The syntax for setting and overriding with environment variables is correct.
- Maintainability: Using environment variables (
${?GRAPHQL_VERBOSE_LOGGING}and${?GRAPHQL_VERBOSE_LONG_QUERY_MILLIS}) for these settings enhances configurability and maintainability, allowing different environments to easily override these values without code changes.
301-301: Review of Unchanged Entity Client SettingThe explicit definition of
entityClient.restli.get.batchConcurrencywith a fallback to an environment variable (${?ENTITY_CLIENT_RESTLI_GET_BATCH_CONCURRENCY}) is a good practice. This ensures that the application can adapt to different environments without requiring code changes, which is crucial for maintaining consistent behavior across deployments.datahub-frontend/app/controllers/Application.java (3)
12-13: Approved: Import statements.The new imports for
JsonNodeandObjectMapperare necessary for handling JSON operations in thelogSlowQuerymethod.
20-20: Approved: Import statement.The import of
Instantis necessary for measuring the duration of requests, which is a part of the new feature.
139-141: Approved: Time measurement initiation.The use of
Instant.now()to capture the start time of the request is appropriate for measuring the request duration.
| // Log the query if it takes longer than the configured threshold and verbose logging is enabled | ||
| boolean verboseGraphQLLogging = _config.getBoolean("graphql.verbose.logging"); | ||
| int verboseGraphQLLongQueryMillis = _config.getInt("graphql.verbose.slowQueryMillis"); | ||
| Instant finish = Instant.now(); | ||
| long timeElapsed = Duration.between(start, finish).toMillis(); | ||
| if (verboseGraphQLLogging && timeElapsed >= verboseGraphQLLongQueryMillis) { | ||
| logSlowQuery(request, resolvedUri, timeElapsed); | ||
| } | ||
|
|
There was a problem hiding this comment.
Review: Logging slow GraphQL queries.
The implementation correctly checks if verbose logging is enabled and if the query duration exceeds the threshold before logging. However, consider adding error handling for potential exceptions when accessing configuration values.
Consider adding a try-catch block around the configuration access to handle possible ConfigException:
try {
boolean verboseGraphQLLogging = _config.getBoolean("graphql.verbose.logging");
int verboseGraphQLLongQueryMillis = _config.getInt("graphql.verbose.slowQueryMillis");
} catch (ConfigException e) {
_logger.error("Error accessing configuration for GraphQL logging.", e);
}| * Called if verbose logging is enabled and request takes longer that the slow query milliseconds defined in the config | ||
| * @param request GraphQL request that was made | ||
| * @param resolvedUri URI that was requested | ||
| * @param duration How long the query took to complete | ||
| */ | ||
| private void logSlowQuery(Http.Request request, String resolvedUri, float duration) { | ||
| StringBuilder jsonBody = new StringBuilder(); | ||
| Optional<Cookie> actorCookie = request.getCookie("actor"); | ||
| String actorValue = actorCookie.isPresent() ? actorCookie.get().value() : "N/A"; | ||
|
|
||
| try { | ||
| ObjectMapper mapper = new ObjectMapper(); | ||
| JsonNode jsonNode = request.body().asJson(); | ||
| ((ObjectNode) jsonNode).remove("query"); | ||
| jsonBody.append(mapper.writerWithDefaultPrettyPrinter().writeValueAsString(jsonNode)); | ||
| } | ||
| catch (Exception e) { | ||
| _logger.info("GraphQL Request Received: {}, Unable to parse JSON body", resolvedUri); | ||
| } | ||
| String jsonBodyStr = jsonBody.toString(); | ||
| _logger.info("Slow GraphQL Request Received: {}, Request query string: {}, Request actor: {}, Request JSON: {}, Request completed in {} ms", | ||
| resolvedUri, | ||
| request.queryString(), | ||
| actorValue, | ||
| jsonBodyStr, | ||
| duration); | ||
| } |
There was a problem hiding this comment.
Review: logSlowQuery method implementation.
The method implementation for logging slow GraphQL queries is mostly correct. However, there are a few areas of improvement:
- The removal of the "query" field from the JSON body is a good practice to avoid logging sensitive data, but ensure that the JSON body is not null before casting and modifying it.
- The exception handling could be more specific by catching more specific exceptions than the general
Exception. - The logging statement at the end could benefit from more structured logging instead of concatenating strings.
Consider the following improvements:
- Check for null before casting the JSON body:
if (jsonNode != null && jsonNode.isObject()) {
((ObjectNode) jsonNode).remove("query");
}- Catch more specific exceptions:
catch (IOException e) {
_logger.info("GraphQL Request Received: {}, Unable to parse JSON body due to IO issues", resolvedUri, e);
}- Use structured logging:
_logger.info("Slow GraphQL Request Received: URI={}, QueryString={}, Actor={}, JSON={}, Duration={} ms",
resolvedUri, request.queryString(), actorValue, jsonBodyStr, duration);
Is this something that is wanted upstream? We added this option to log slow GraphQL queries so that we could find which queries need to be optimized or pages that could potentially cause issues.
Checklist
Summary by CodeRabbit
New Features
Bug Fixes
Documentation