-
Notifications
You must be signed in to change notification settings - Fork 4.7k
fix: add INFO-level logging to critical code paths for RCA diagnosability #42082
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
base: release
Are you sure you want to change the base?
Changes from all commits
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -1,16 +1,19 @@ | ||
| package com.appsmith.server.authentication.handlers.ce; | ||
|
|
||
| import lombok.extern.slf4j.Slf4j; | ||
| import org.springframework.http.HttpStatus; | ||
| import org.springframework.http.server.reactive.ServerHttpResponse; | ||
| import org.springframework.security.access.AccessDeniedException; | ||
| import org.springframework.security.web.server.authorization.ServerAccessDeniedHandler; | ||
| import org.springframework.web.server.ServerWebExchange; | ||
| import reactor.core.publisher.Mono; | ||
|
|
||
| @Slf4j | ||
| public class AccessDeniedHandlerCE implements ServerAccessDeniedHandler { | ||
| @Override | ||
| public Mono<Void> handle(ServerWebExchange exchange, AccessDeniedException denied) { | ||
| return Mono.fromRunnable(() -> { | ||
| log.warn("Access denied: path={}", exchange.getRequest().getPath()); | ||
|
Contributor
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. 🔒 Security & Privacy | 🟠 Major Apply one bounded redaction policy to operational telemetry. These changes emit request-, provider-, and upstream-controlled values without one common length, cardinality, and redaction policy. CRLF replacement alone does not prevent sensitive data or high-cardinality telemetry.
Repository verification#!/usr/bin/env bash
set -euo pipefail
rg -n -C 5 \
'Access denied: path=|LOGIN_FAILURE|Datasource connection creation failed|errorMessage|doOnError\(e -> log\.error' \
app/server/appsmith-server/src/main/java \
app/server/appsmith-server/src/test/java \
--glob '*.java'📍 Affects 4 files
🤖 Prompt for AI Agents |
||
| ServerHttpResponse response = exchange.getResponse(); | ||
| response.setStatusCode(HttpStatus.UNAUTHORIZED); | ||
| }); | ||
|
|
||
| Original file line number | Diff line number | Diff line change | ||||||||||||||||
|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|
|
|
@@ -24,17 +24,30 @@ public class AuthenticationFailureHandlerCE implements ServerAuthenticationFailu | |||||||||||||||||
| @Override | ||||||||||||||||||
| public Mono<Void> onAuthenticationFailure(WebFilterExchange webFilterExchange, AuthenticationException exception) { | ||||||||||||||||||
| String source = exception instanceof OAuth2AuthenticationException | ||||||||||||||||||
| ? ((OAuth2AuthenticationException) exception).getError().getErrorCode() | ||||||||||||||||||
| ? sanitizeLogInput( | ||||||||||||||||||
| ((OAuth2AuthenticationException) exception).getError().getErrorCode()) | ||||||||||||||||||
| : SOURCE_FORM; | ||||||||||||||||||
|
|
||||||||||||||||||
| String errorMessage = exception.getMessage(); | ||||||||||||||||||
|
|
||||||||||||||||||
| log.warn( | ||||||||||||||||||
| "Authentication failed: source={}, errorCode={}", | ||||||||||||||||||
| source, | ||||||||||||||||||
| exception.getClass().getSimpleName()); | ||||||||||||||||||
|
hacktron-app[bot] marked this conversation as resolved.
Comment on lines
+33
to
+36
Contributor
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. 🎯 Functional Correctness | 🟡 Minor | ⚡ Quick win Use the correct field name in the warning.
Proposed fix- "Authentication failed: source={}, errorCode={}",
+ "Authentication failed: source={}, exceptionType={}",📝 Committable suggestion
Suggested change
🤖 Prompt for AI Agents |
||||||||||||||||||
|
|
||||||||||||||||||
| meterRegistry | ||||||||||||||||||
| .counter(LOGIN_FAILURE, "source", source, "message", errorMessage) | ||||||||||||||||||
| .increment(); | ||||||||||||||||||
| return authenticationFailureRetryHandler.retryAndRedirectOnAuthenticationFailure(webFilterExchange, exception); | ||||||||||||||||||
| } | ||||||||||||||||||
|
|
||||||||||||||||||
| private static String sanitizeLogInput(String input) { | ||||||||||||||||||
| if (input == null) { | ||||||||||||||||||
| return null; | ||||||||||||||||||
| } | ||||||||||||||||||
| return input.replaceAll("[\\r\\n]", "_"); | ||||||||||||||||||
| } | ||||||||||||||||||
|
|
||||||||||||||||||
| public Mono<Void> handleErrorRedirect(WebFilterExchange webFilterExchange) { | ||||||||||||||||||
| String error = | ||||||||||||||||||
| webFilterExchange.getExchange().getRequest().getQueryParams().getFirst("error"); | ||||||||||||||||||
|
|
||||||||||||||||||
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -1982,6 +1982,10 @@ protected Mono<GitPullDTO> pullArtifact(Artifact baseArtifact, Artifact branched | |
| GitArtifactMetadata branchedGitMetadata = branchedArtifact.getGitArtifactMetadata(); | ||
| ArtifactType artifactType = baseArtifact.getArtifactType(); | ||
| String baseArtifactId = branchedGitMetadata.getDefaultArtifactId(); | ||
| String branchName = branchedGitMetadata.getRefName(); | ||
|
|
||
| log.info("Git pull started: artifactId={}, branch={}", baseArtifactId, branchName); | ||
| long pullStartTime = System.currentTimeMillis(); | ||
|
Comment on lines
+1985
to
+1988
Contributor
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. 🎯 Functional Correctness | 🟡 Minor | ⚡ Quick win 🧩 Analysis chain🏁 Script executed: #!/bin/bash
set -eu
file="app/server/appsmith-server/src/main/java/com/appsmith/server/git/central/CentralGitServiceCEImpl.java"
printf '%s\n' '--- target method context ---'
sed -n '1935,2050p' "$file"
printf '%s\n' '--- reactive timing and pull call sites ---'
rg -n -C 3 'pullStartTime|Git pull started|durationMs|doOnSuccess|doOnError|Mono\.defer|doOnSubscribe' "$file"
printf '%s\n' '--- method outline ---'
ast-grep outline "$file" | sed -n '1,220p'Repository: appsmithorg/appsmith Length of output: 17457 🏁 Script executed: #!/bin/bash
set -eu
file="app/server/appsmith-server/src/main/java/com/appsmith/server/git/central/CentralGitServiceCEImpl.java"
sed -n '1935,2050p' "$file"
rg -n -C 3 'pullStartTime|Git pull started|durationMs|doOnSuccess|doOnError|Mono\.defer|doOnSubscribe' "$file"
ast-grep outline "$file" | sed -n '1,220p'Repository: appsmithorg/appsmith Length of output: 17360 🏁 Script executed: #!/bin/bash
set -eu
file="app/server/appsmith-server/src/main/java/com/appsmith/server/git/central/CentralGitServiceCEImpl.java"
printf '%s\n' '--- pullArtifact call sites ---'
rg -n -C 4 'pullArtifact\s*\(' app/server --glob '*.java' --glob '*Test.java' | sed -n '1,260p'
printf '%s\n' '--- related pull tests and assertions ---'
rg -n -C 4 'pullArtifact|Git pull started|Git pull completed|Git pull failed|durationMs' app/server --glob '*Test.java' | sed -n '1,320p'
printf '%s\n' '--- return shapes in the pull pipeline ---'
sed -n '2055,2145p' "$file"
printf '%s\n' '--- Reactor and test dependency versions ---'
rg -n -C 2 'reactor-core|reactor-test|spring-boot-starter-webflux|spring-boot' app/server --glob 'pom.xml' --glob '*.xml' | sed -n '1,220p'Repository: appsmithorg/appsmith Length of output: 32647 🏁 Script executed: #!/bin/bash
set -eu
file="app/server/appsmith-server/src/main/java/com/appsmith/server/git/central/CentralGitServiceCEImpl.java"
rg -n -C 4 'pullArtifact\s*\(' app/server --glob '*.java' --glob '*Test.java' | sed -n '1,260p'
rg -n -C 4 'pullArtifact|Git pull started|Git pull completed|Git pull failed|durationMs' app/server --glob '*Test.java' | sed -n '1,320p'
sed -n '2055,2145p' "$file"
rg -n -C 2 'reactor-core|reactor-test|spring-boot-starter-webflux|spring-boot' app/server --glob 'pom.xml' --glob '*.xml' | sed -n '1,220p'Repository: appsmithorg/appsmith Length of output: 33178 🏁 Script executed: #!/bin/bash
set -eu
python3 - <<'PY'
from pathlib import Path
import re
path = Path("app/server/appsmith-server/src/main/java/com/appsmith/server/git/central/CentralGitServiceCEImpl.java")
text = path.read_text()
start = text.index(" protected Mono<GitPullDTO> pullArtifact(")
end = text.index("\n /**\n * Method to pull the files from remote repo", start)
method = text[start:end]
log_pos = method.index('log.info("Git pull started:')
timer_pos = method.index("long pullStartTime = System.currentTimeMillis();")
subscribe_pos = method.index(".subscribe(")
assert log_pos < subscribe_pos
assert timer_pos < subscribe_pos
assert "Mono.usingWhen(" in method
assert "Mono.defer(" in text[text.index("private Mono<GitPullDTO> pullAndRehydrateArtifact"):end]
print("source_check: start log and wall-clock timestamp precede inner subscription")
class ColdMono:
def __init__(self, events):
self.events = events
def subscribe(self):
self.events.append("work subscribed")
def assemble():
events = ["start logged", "timestamp captured"]
return events, ColdMono(events)
events, mono = assemble()
assert events == ["start logged", "timestamp captured"]
assert "work subscribed" not in events
events.append("time passes before subscription")
mono.subscribe()
assert events[-2:] == ["time passes before subscription", "work subscribed"]
print("behavior_check: assembly side effects occur before delayed subscription")
events, mono = assemble()
assert events == ["start logged", "timestamp captured"]
print("behavior_check: assembly side effects occur even when the returned publisher is never subscribed")
PYRepository: appsmithorg/appsmith Length of output: 247 🏁 Script executed: #!/bin/bash
set -eu
python3 - <<'PY'
from pathlib import Path
path = Path("app/server/appsmith-server/src/main/java/com/appsmith/server/git/central/CentralGitServiceCEImpl.java")
text = path.read_text()
protected_start = text.index(" protected Mono<GitPullDTO> pullArtifact(")
protected_end = text.index(
"\n /**\n * Method to pull the files from remote repo", protected_start
)
method = text[protected_start:protected_end]
log_pos = method.index('log.info("Git pull started:')
timer_pos = method.index("long pullStartTime = System.currentTimeMillis();")
subscribe_pos = method.index(".subscribe(")
assert log_pos < subscribe_pos
assert timer_pos < subscribe_pos
assert "Mono.usingWhen(" in method
private_start = text.index(
" private Mono<GitPullDTO> pullAndRehydrateArtifact", protected_end
)
private_end = text.index(
"\n `@Override`\n public Mono<BranchTrackingStatus> fetchRemoteChanges",
private_start
)
private_method = text[private_start:private_end]
assert "return Mono.defer(" in private_method
print("source_check: start logging and wall-clock timestamp precede the inner subscription")
print("source_check: the pull pipeline itself is deferred")
class ColdMono:
def __init__(self, events):
self.events = events
def subscribe(self):
self.events.append("work subscribed")
def assemble():
events = ["start logged", "timestamp captured"]
return events, ColdMono(events)
events, mono = assemble()
assert events == ["start logged", "timestamp captured"]
assert "work subscribed" not in events
events.append("time passes before subscription")
mono.subscribe()
assert events[-2:] == ["time passes before subscription", "work subscribed"]
print("behavior_check: assembly side effects precede delayed subscription")
events, _ = assemble()
assert events == ["start logged", "timestamp captured"]
print("behavior_check: assembly side effects occur without subscription")
PYRepository: appsmithorg/appsmith Length of output: 425 Start the pull timer on subscription.
🤖 Prompt for AI Agents |
||
|
|
||
| Mono<GitPullDTO> lockHandledpullDTOMono = Mono.usingWhen( | ||
| gitRedisUtils.acquireGitLock(artifactType, baseArtifactId, GitCommandConstants.PULL, TRUE), | ||
|
|
@@ -2015,8 +2019,19 @@ protected Mono<GitPullDTO> pullArtifact(Artifact baseArtifact, Artifact branched | |
| .name(GitSpan.OPS_PULL) | ||
| .tap(Micrometer.observation(observationRegistry)); | ||
|
|
||
| return Mono.create( | ||
| sink -> lockHandledpullDTOMono.subscribe(sink::success, sink::error, null, sink.currentContext())); | ||
| return Mono.create(sink -> lockHandledpullDTOMono | ||
| .doOnSuccess(result -> log.info( | ||
| "Git pull completed: artifactId={}, branch={}, durationMs={}", | ||
| baseArtifactId, | ||
| branchName, | ||
| System.currentTimeMillis() - pullStartTime)) | ||
| .doOnError(error -> log.warn( | ||
| "Git pull failed: artifactId={}, branch={}, durationMs={}", | ||
| baseArtifactId, | ||
| branchName, | ||
| System.currentTimeMillis() - pullStartTime, | ||
| error)) | ||
| .subscribe(sink::success, sink::error, null, sink.currentContext())); | ||
| } | ||
|
|
||
| /** | ||
|
|
||
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -0,0 +1,45 @@ | ||
| package com.appsmith.server.authentication.handlers.ce; | ||
|
|
||
| import com.appsmith.server.authentication.helpers.AuthenticationFailureRetryHandler; | ||
| import io.micrometer.core.instrument.MeterRegistry; | ||
| import io.micrometer.core.instrument.simple.SimpleMeterRegistry; | ||
| import org.junit.jupiter.api.BeforeEach; | ||
| import org.junit.jupiter.api.Test; | ||
| import org.springframework.security.oauth2.core.OAuth2AuthenticationException; | ||
| import org.springframework.security.oauth2.core.OAuth2Error; | ||
| import reactor.core.publisher.Mono; | ||
|
|
||
| import static org.assertj.core.api.Assertions.assertThat; | ||
| import static org.mockito.ArgumentMatchers.any; | ||
| import static org.mockito.Mockito.mock; | ||
| import static org.mockito.Mockito.when; | ||
|
|
||
| class AuthenticationFailureHandlerCETest { | ||
|
|
||
| private AuthenticationFailureHandlerCE handler; | ||
| private MeterRegistry meterRegistry; | ||
|
|
||
| @BeforeEach | ||
| void setUp() { | ||
| AuthenticationFailureRetryHandler retryHandler = mock(AuthenticationFailureRetryHandler.class); | ||
| when(retryHandler.retryAndRedirectOnAuthenticationFailure(any(), any())).thenReturn(Mono.empty()); | ||
| meterRegistry = new SimpleMeterRegistry(); | ||
| handler = new AuthenticationFailureHandlerCE(retryHandler, meterRegistry); | ||
| } | ||
|
|
||
| @Test | ||
| void onAuthenticationFailure_sanitizesCrlfInOAuth2ErrorCode() { | ||
| String maliciousErrorCode = "invalid_grant\r\nINFO: Forged log entry"; | ||
| OAuth2Error error = new OAuth2Error(maliciousErrorCode, "some description", null); | ||
| OAuth2AuthenticationException exception = new OAuth2AuthenticationException(error, "auth failed"); | ||
|
|
||
| // The handler should not throw — it sanitizes and logs safely | ||
| handler.onAuthenticationFailure(null, exception).block(); | ||
|
|
||
| // Verify the metric tag was recorded with sanitized source (no CRLF) | ||
| String recordedSource = | ||
| meterRegistry.get("appsmith.login_failure").counter().getId().getTag("source"); | ||
| assertThat(recordedSource).doesNotContain("\r").doesNotContain("\n"); | ||
| assertThat(recordedSource).isEqualTo("invalid_grant__INFO: Forged log entry"); | ||
|
Comment on lines
+32
to
+43
Contributor
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. 🔒 Security & Privacy | 🟠 Major | ⚡ Quick win 🧩 Analysis chain🏁 Script executed: #!/bin/bash
set -euo pipefail
rg -n -C 3 'spring-security|spring-boot-starter-security' app/server --glob 'pom.xml' || true
rg -n -C 6 'exception\.getMessage\(\)|counter\(.*message|log\.warn|OAuth2AuthenticationException' \
app/server/appsmith-server/src/main app/server/appsmith-server/src/testRepository: appsmithorg/appsmith Length of output: 50377 🏁 Script executed: #!/bin/bash
set -euo pipefail
test_file="$(fd -t f 'AuthenticationFailureHandlerCETest.java' . | head -n 1)"
handler_file="$(fd -t f 'AuthenticationFailureHandlerCE.java' . | head -n 1)"
printf '%s\n' "TEST=$test_file" "HANDLER=$handler_file"
ast-grep outline "$test_file" --lang java
ast-grep outline "$handler_file" --lang java
printf '\n--- test ---\n'
cat -n "$test_file"
printf '\n--- handler ---\n'
cat -n "$handler_file"
printf '\n--- focused dependency declarations ---\n'
rg -n -C 4 'spring-security|spring-boot-starter-security' app/server --glob 'pom.xml' | head -n 160Repository: appsmithorg/appsmith Length of output: 9426 🏁 Script executed: #!/bin/bash
set -euo pipefail
printf '%s\n' '--- managed Spring versions ---'
rg -n -C 3 'spring-boot.version|spring-security.version|spring-security' \
app/server/pom.xml app/server/appsmith-server/pom.xml pom.xml 2>/dev/null | head -n 200
printf '%s\n' '--- authentication failure handler references ---'
rg -n -C 5 'handleErrorRedirect|onAuthenticationFailure|AuthenticationFailureHandlerCE' \
app/server/appsmith-server/src/main app/server/appsmith-server/src/test \
--glob '*.java' | head -n 320
printf '%s\n' '--- exact metric tag construction ---'
rg -n -C 3 'LOGIN_FAILURE|appsmith\.login_failure' \
app/server/appsmith-server/src/main/java/com/appsmith/server/authentication \
app/server/appsmith-server/src/test/java/com/appsmith/server/authentication \
--glob '*.java' | head -n 240Repository: appsmithorg/appsmith Length of output: 1874 🏁 Script executed: #!/bin/bash
set -u
printf '%s\n' '--- POM files ---'
git ls-files '*pom.xml' | head -n 120
printf '%s\n' '--- Spring version declarations ---'
for f in $(git ls-files '*pom.xml'); do
rg -n -H -C 3 'spring-boot.version|spring-security.version|spring-boot-dependencies|spring-security' "$f" || true
done | head -n 260
printf '%s\n' '--- handler references ---'
rg -n -C 5 'handleErrorRedirect|onAuthenticationFailure|AuthenticationFailureHandlerCE' \
app/server/appsmith-server/src/main app/server/appsmith-server/src/test \
--glob '*.java' || true
printf '%s\n' '--- login failure metric construction ---'
rg -n -C 3 'LOGIN_FAILURE|appsmith\.login_failure' \
app/server/appsmith-server/src/main/java/com/appsmith/server/authentication \
app/server/appsmith-server/src/test/java/com/appsmith/server/authentication \
--glob '*.java' || trueRepository: appsmithorg/appsmith Length of output: 23127 🌐 Web query:
💡 Result: In Spring Security 6.4, the OAuth2AuthenticationException class provides multiple constructors to handle OAuth 2.0-related authentication errors [1][2]. These constructors often accept an OAuth2Error object, which serves as a representation of the OAuth 2.0 error [3]. When an OAuth2AuthenticationException is constructed using only an OAuth2Error object, the exception's detail message is automatically populated using the description retrieved from that error [4]. Specifically, the implementation performs the following: public OAuth2AuthenticationException(OAuth2Error error) { this(error, error.getDescription); } In this context, the error.getDescription method returns the error description associated with the OAuth2Error instance [3][5]. If the description is not available in the OAuth2Error, it may return null [6][7], which is then passed as the message to the superclass constructor (AuthenticationException) [4]. Other available constructors in Spring Security 6.4 allow for explicit messaging, such as: - OAuth2AuthenticationException(OAuth2Error error, String message) [1][8] - OAuth2AuthenticationException(OAuth2Error error, String message, Throwable cause) [1][8] These constructors permit you to override or provide a custom detail message independently of the description contained within the OAuth2Error object [8]. Citations:
🏁 Script executed: #!/bin/bash
set -euo pipefail
python3 - <<'PY'
from pathlib import Path
import re
handler = Path("app/server/appsmith-server/src/main/java/com/appsmith/server/authentication/handlers/ce/AuthenticationFailureHandlerCE.java").read_text()
test = Path("app/server/appsmith-server/src/test/java/com/appsmith/server/authentication/handlers/ce/AuthenticationFailureHandlerCETest.java").read_text()
assert re.search(
r'counter\(LOGIN_FAILURE,\s*"source",\s*source,\s*"message",\s*errorMessage\)',
handler,
)
assert re.search(r'String errorMessage = exception\.getMessage\(\);', handler)
assert re.search(
r'log\.warn\(\s*"Authentication failed: source=\{\}, errorCode=\{\}",\s*source,\s*exception\.getClass\(\)\.getSimpleName\(\)',
handler,
re.S,
)
assert 'new OAuth2AuthenticationException(error, "auth failed")' in test
assert 'getTag("message")' not in test
assert 'getTag("source")' in test
print("message metric tag: direct exception.getMessage()")
print("warning log inputs: sanitized source and exception class only")
print("test message: explicit safe literal 'auth failed'")
print("test assertions: source tag only")
PYRepository: appsmithorg/appsmith Length of output: 353 Test and sanitize the exception message metric tag. Construct 🤖 Prompt for AI Agents |
||
| } | ||
| } | ||
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
📐 Maintainability & Code Quality | 🟡 Minor | ⚡ Quick win
🧩 Analysis chain
🏁 Script executed:
Repository: appsmithorg/appsmith
Length of output: 47091
🏁 Script executed:
Repository: appsmithorg/appsmith
Length of output: 50376
Attach merge failure logging to every failure path.
The
GitAPIExceptioncatch does not cover failures fromGit.open,Mono.usingcleanup, ortimeout. WhenkeepWorkingDirChangesis false,onErrorResumeconverts merge failures into a successfulStringafter reset and replaces reset failures with a newThrowable. Log before recovery and at the outerMono.usingboundary, and preserve the originalThrowable.🤖 Prompt for AI Agents