Skip to content

Commit e998fa2

Browse files
k-wallSamBarker
andauthored
fix(authorization): Log deny actions only if not empty (kroxylicious#3001)
* fix(authorization): Log deny actions only if not empty Signed-off-by: Keith Wall <kwall@apache.org> * Add test asserting we don't log empty deny events. Signed-off-by: Sam Barker <sam@quadrocket.co.uk> * Assert that we log an outcome for every request. Note we draw a distinction between things which cannot be authorized, API_VERSIONS for example, and requests which contained no authorizable actions. Signed-off-by: Sam Barker <sam@quadrocket.co.uk> * Fix formatting Signed-off-by: Sam Barker <sam@quadrocket.co.uk> --------- Signed-off-by: Keith Wall <kwall@apache.org> Signed-off-by: Sam Barker <sam@quadrocket.co.uk> Co-authored-by: Sam Barker <sam@quadrocket.co.uk>
1 parent 7d0ff44 commit e998fa2

File tree

4 files changed

+55
-6
lines changed

4 files changed

+55
-6
lines changed

kroxylicious-filters/kroxylicious-authorization/pom.xml

Lines changed: 5 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -102,7 +102,11 @@
102102
<artifactId>mockito-junit-jupiter</artifactId>
103103
<scope>test</scope>
104104
</dependency>
105-
105+
<dependency>
106+
<groupId>io.github.hakky54</groupId>
107+
<artifactId>logcaptor</artifactId>
108+
<scope>test</scope>
109+
</dependency>
106110
</dependencies>
107111

108112
</project>

kroxylicious-filters/kroxylicious-authorization/src/main/java/io/kroxylicious/filter/authorization/AuthorizationFilter.java

Lines changed: 18 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -58,6 +58,7 @@ public class AuthorizationFilter implements RequestFilter, ResponseFilter {
5858
@Override
5959
CompletionStage<ResponseFilterResult> onResponse(ResponseHeaderData header, ApiVersionsResponseData response, FilterContext context,
6060
AuthorizationFilter authorizationFilter) {
61+
AuthorizationFilter.nonAuthorizableRequest(context);
6162
return authorizationFilter.checkCompat(header, response, context);
6263
}
6364
});
@@ -150,11 +151,27 @@ public AuthorizationFilter(Authorizer authorizer) {
150151
CompletionStage<AuthorizeResult> authorization(FilterContext context, List<Action> actions) {
151152
return authorizer.authorize(context.authenticatedSubject(), actions)
152153
.thenApply(authz -> {
153-
LOG.info("DENY {} to {}", authz.denied(), authz.subject());
154+
if (!authz.denied().isEmpty()) {
155+
LOG.info("DENY {} to {}", authz.denied(), authz.subject());
156+
}
157+
else if (!authz.allowed().isEmpty()) {
158+
LOG.debug("ALLOW {} to {}", authz.allowed(), authz.subject());
159+
}
160+
else if (actions.isEmpty()) {
161+
LOG.debug("ALLOW {} no authorizable actions", authz.subject());
162+
}
154163
return authz;
155164
});
156165
}
157166

167+
static void nonAuthorizableRequest(FilterContext context) {
168+
LOG.debug("NON-AUTHORIZABLE request from {}", context.authenticatedSubject());
169+
}
170+
171+
static void nonAuthorizableResponse(FilterContext context) {
172+
LOG.debug("NON-AUTHORIZABLE response from {}", context.authenticatedSubject());
173+
}
174+
158175
<R> void pushInflightState(RequestHeaderData header, InflightState<R> inflightState) {
159176
var existing = this.inflightState.put(header.correlationId(), inflightState);
160177
if (existing != null) {

kroxylicious-filters/kroxylicious-authorization/src/main/java/io/kroxylicious/filter/authorization/Passthrough.java

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -54,6 +54,7 @@ CompletionStage<RequestFilterResult> onRequest(RequestHeaderData header,
5454
Q request,
5555
FilterContext context,
5656
AuthorizationFilter authorizationFilter) {
57+
AuthorizationFilter.nonAuthorizableRequest(context);
5758
return context.forwardRequest(header, request);
5859
}
5960

@@ -62,7 +63,7 @@ CompletionStage<ResponseFilterResult> onResponse(ResponseHeaderData header,
6263
S response,
6364
FilterContext context,
6465
AuthorizationFilter authorizationFilter) {
65-
66+
AuthorizationFilter.nonAuthorizableResponse(context);
6667
return context.forwardResponse(header, response);
6768
}
6869
}

kroxylicious-filters/kroxylicious-authorization/src/test/java/io/kroxylicious/filter/authorization/AuthorizationFilterTest.java

Lines changed: 30 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -42,18 +42,22 @@
4242
import io.kroxylicious.test.requestresponsetestdef.KafkaApiMessageConverter;
4343

4444
import edu.umd.cs.findbugs.annotations.NonNull;
45+
import nl.altindag.log.LogCaptor;
4546

4647
import static java.util.EnumSet.complementOf;
4748
import static java.util.EnumSet.copyOf;
4849
import static java.util.EnumSet.of;
4950
import static org.assertj.core.api.Assertions.assertThat;
51+
import static org.assertj.core.api.Assertions.fail;
5052

5153
class AuthorizationFilterTest {
5254

5355
private static final ObjectMapper MAPPER = new ObjectMapper(new YAMLFactory());
5456

5557
private static final Pattern TEST_RESOURCE_FILTER = Pattern.compile("scenarios/.*\\.yaml");
5658

59+
private static final LogCaptor logCaptor = LogCaptor.forClass(AuthorizationFilter.class);
60+
5761
static Stream<Arguments> authorization() throws Exception {
5862
List<ClassPath.ResourceInfo> resources = ClassPath.from(AuthorizationFilterTest.class.getClassLoader()).getResources().stream()
5963
.filter(ri -> TEST_RESOURCE_FILTER.matcher(ri.getResourceName()).matches()).toList();
@@ -96,13 +100,37 @@ void authorization(ScenarioDefinition definition) {
96100
if (!mockUpstream.isFinished()) {
97101
throw new IllegalStateException("test has finished, but mock responses are still queued");
98102
}
103+
104+
assertOutcomeLogged();
99105
// we expect that any inflight state pushed during a request is always popped on the corresponding response
100106
// if it is non-empty then we may have a memory leak
101107
assertThat(authorizationFilter.inflightState())
102108
.describedAs("inflight state")
103109
.isEmpty();
104110
}
105111

112+
private static void assertOutcomeLogged() {
113+
assertThat(logCaptor.getLogEvents())
114+
.isNotEmpty()
115+
.allSatisfy(event -> {
116+
if ("INFO".equalsIgnoreCase(event.getLevel())) {
117+
assertThat(event.getFormattedMessage())
118+
.startsWith("DENY")
119+
.doesNotContain("[]");
120+
}
121+
else if ("DEBUG".equalsIgnoreCase(event.getLevel())) {
122+
assertThat(event.getFormattedMessage())
123+
.containsAnyOf("ALLOW", "NON-AUTHORIZABLE")
124+
.doesNotContain("[]");
125+
}
126+
else {
127+
// false positive `fail` is annotated `CanIgnoreReturnValue` which is not supposed to trigger the warnings
128+
// noinspection ResultOfMethodCallIgnored
129+
fail("unexpected event logged: %s", event.getFormattedMessage());
130+
}
131+
});
132+
}
133+
106134
private static void handleRequestForward(ScenarioDefinition definition, CompletionStage<RequestFilterResult> stage, MockUpstream mockUpstream, Subject subject,
107135
Map<Uuid, String> topicNames, AuthorizationFilter authorizationFilter, ApiKeys apiKeys, short version) {
108136
RequestFilterResult actual = assertThat(stage).succeedsWithin(Duration.ZERO).actual();
@@ -147,9 +175,8 @@ private static void handleRequestForward(ScenarioDefinition definition, Completi
147175
throw new IllegalStateException("mock upstream still has responses queued, but filter short circuit responded");
148176
}
149177
if (definition.then().expectedErrorResponse() != null) {
150-
assertThat(actual).isInstanceOfSatisfying(MockFilterContext.ErrorRequestFilterResult.class, result -> {
151-
assertThat(result.apiException()).isEqualTo(definition.then().expectedErrorResponse().exception());
152-
});
178+
assertThat(actual).isInstanceOfSatisfying(MockFilterContext.ErrorRequestFilterResult.class,
179+
result -> assertThat(result.apiException()).isEqualTo(definition.then().expectedErrorResponse().exception()));
153180
}
154181
else {
155182
if (definition.then().expectedResponseHeader() != null) {

0 commit comments

Comments
 (0)