Do not log session ids, access tokens and password attributes - #1127
Conversation
AuthInterceptor (openam-mcp-server) wrote the OpenAM session id at INFO when refreshing a near-expired token and the OAuth2 access token at WARN when userinfo rejected it; the Cassandra CTS adapter logged the whole CTS Token (tokenId included) when a field could not be read, and the Cassandra IdRepo logged the full attribute map - userPassword included - when setAttributes/setBinaryAttributes failed. A session id or token in a log file is enough to hijack the session. Log a masked prefix of the token instead, and only attribute names for the IdRepo. Tests capture the logger output and assert the raw values are absent. Closes CodeQL alerts java/sensitive-log OpenIdentityPlatform#243, OpenIdentityPlatform#246, OpenIdentityPlatform#247, OpenIdentityPlatform#252, OpenIdentityPlatform#270, OpenIdentityPlatform#271
vharseko
added
java
![github-advanced-security[bot]](https://avatars.githubusercontent.com/in/57789?s=60&v=4){kind=small}
maximthomas
left a comment
maximthomas
left a comment
There was a problem hiding this comment.
praise: Tight diff, honest tests, and two silent bugs fixed on the way.
AuthInterceptorTestdrives the realpreHandleUsernamePassword/preHandleOAuth/accessTokenValidwith aListAppender, andanyMatch("about to expire")makes a vacuous pass impossible.Repo.java:439also repairs the pre-existing four-placeholders-for-five-arguments mismatch, soe.getMessage()is actually printed now.TokenStorageAdapter.java:128keeps field / type / masked id /e.toString()— enough to find the bad column — and the label finally saysupdate, notcreate.- Exactly six log sites changed for six alerts; nothing else touched.
issue (non-blocking): ExecuteCallback.onFailure prints the raw coreTokenId — for OAuth2 the hex of the bearer — on any Cassandra failure inside the same update().
openam-cassandra/openam-cassandra-datastore/src/main/java/org/openidentityplatform/openam/cassandra/ExecuteCallback.java:98-99, :116; openam-cassandra/openam-cassandra-cts/src/main/java/org/openidentityplatform/openam/cassandra/TokenStorageAdapter.java:143-145
update() binds every CoreTokenField with setString and hands the statement to execute() / executeAsync(); both route errors to onFailure(), which logs debugQuery(statement) at WARN with every text column inlined verbatim. coreTokenId for OAuth2 is Hex.encodeHexString(rawToken) (TokenIdFactory.toOAuthTokenStoreId → KeyConversion.encodeKey), reversible with decodeKey; for sessions it is the storage key encrypted with the server encryptor (enableHash defaults to false). Same WARN level as the line this PR masks, and the real callers (OAuthTokenStore:107, SessionPersistenceStore:131) end here. Not one of the six alerts — a linked follow-up is fine — but until it is masked the CTS half of the title holds only for the field-read branch.
// ExecuteCallback.debugQuery, text branch
String name = c.getName().asInternal();
String v = ((DefaultBoundStatement) statement).getString(c.getName());
if (name.equals("coreTokenId") || name.equals("coreTokenUserId") || name.startsWith("coreTokenString")) {
v = maskTokenId(v); // move the helper somewhere both modules see it
}
query.value = query.value.replace(":" + name, "'" + v + "'");issue (non-blocking): Repo still logs the full attribute map from the three service methods and the full avPairs from search.
openam-cassandra/openam-cassandra-datastore/src/main/java/org/openidentityplatform/openam/cassandra/Repo.java:749, :777, :806, :661
assignService / unassignService / modifyService pass attrMap into setAttributes (masked at :439 now) and, when it throws, log the same map with values one frame up at ERROR. All three also have four placeholders for five arguments, so e.getMessage() is dropped — the mismatch :439 fixed. The maps come from CLI / console / JAX-RPC; no caller traced that puts userPassword there, so lower sensitivity than :439 — same pattern, same file.
logger.error("assignService {} {} {} {}: {}", type, name, serviceName, attrMap.keySet(), e.getMessage());Same at :777, :806; avPairs.keySet() at :661.
suggestion (non-blocking): AuthInterceptor.java:208 still logs the whole /oauth2/userinfo body.
openam-mcp-server/src/main/java/org/openidentityplatform/openam/mcp/server/security/AuthInterceptor.java:208
The branch is reached whenever the body lacks name; for a valid token with openid email scope that is the user's claims (sub, email, …) at WARN on every request. Not a credential, same java/sensitive-log family.
log.warn("got invalid response (claims {}) for access token: {}", response.keySet(), maskToken(accessToken));suggestion (non-blocking): TokenStorageAdapterTest pins the helper, not the call site.
openam-cassandra/openam-cassandra-cts/src/test/java/org/openidentityplatform/openam/cassandra/TokenStorageAdapterTest.java:29-34
Removing maskTokenId(...) from update():128 keeps the test green. The catch is reachable only with a Token whose getAttribute throws (a normally built Token round-trips every field), so it takes a Mockito Token plus a mocked ConnectionFactory → CqlSession → PreparedStatement → BoundStatement chain returning itself — no Cassandra; mockito-core is not in the cts test scope yet, and static_statement_update is a static cache the test must set.
Token token = mock(Token.class);
when(token.getTokenId()).thenReturn("AQIC5wM2LY4SfczntBcXfFoFJwA6zAV2i4fnU8Sd7ao");
when(token.getExpiryTimestamp()).thenReturn(Calendar.getInstance());
when(token.getAttribute(any())).thenThrow(new IllegalArgumentException("boom"));
assertThrows(DataLayerException.class, () -> adapter.update(token, true));
assertTrue(captured.stream().anyMatch(m -> m.contains("AQIC***")));
assertTrue(captured.stream().noneMatch(m -> m.contains("AQIC5wM2")));suggestion (non-blocking): Repo.java:439 / :447 have no test although IdRepoTest already runs setAttributes against an embedded Cassandra.
openam-cassandra/openam-cassandra-datastore/src/test/java/org/openidentityplatform/openam/cassandra/IdRepoTest.java
setBinaryAttributes throws unconditionally, so :447 needs no failure injection: attach a ListAppender to Repo's logger, call it with a userPassword entry, assert the message contains the key and not the value. That is the case that turns red if keySet() is reverted.
Map<String, byte[][]> attrs = Map.of("userPassword", new byte[][] { "s3cret".getBytes(UTF_8) });
assertThrows(IdRepoUnsupportedOpException.class,
() -> repo.setBinaryAttributes(null, IdType.USER, "9170000000", attrs, false));
assertTrue(messages.stream().anyMatch(m -> m.contains("[userPassword]") && !m.contains("s3cret")));Or: the same appender around setAttributes after cassandra.stop() for :439.
suggestion (non-blocking): the entry-point tests only assert that the full token is absent.
openam-mcp-server/src/test/java/org/openidentityplatform/openam/mcp/server/security/AuthInterceptorTest.java:264-266, :292, :313, :327
token.substring(0, 20) or maskToken(<wrong variable>) at the call site both pass; a token inside a logged Throwable is invisible because captureLogs maps getFormattedMessage() only. The AQIC*** shape lives only in the helper test.
assertThat(messages).anyMatch(m -> m.contains("token " + expiredToken.substring(0, 4) + "*** is about to expire"));and in captureLogs:
.map(e -> e.getFormattedMessage()
+ (e.getThrowableProxy() == null ? "" : " " + e.getThrowableProxy().getMessage()))question (non-blocking): the 4-char prefix is the constant AQIC for every SSO token — is correlation intended?
openam-cassandra/openam-cassandra-cts/src/main/java/org/openidentityplatform/openam/cassandra/TokenStorageAdapter.java:72-84, openam-mcp-server/src/main/java/org/openidentityplatform/openam/mcp/server/security/AuthInterceptor.java:74-82
JCEEncryption.addPrefix writes the version byte and two fixed algorithm bytes before the ciphertext, so base64 yields AQIC for every session id (the fixture in TokenStorageAdapterTest starts with it) and c66 keeps it. The two session sites in AuthInterceptor (:143, :183) will always read token AQIC***; OAuth2 UUIDs and CTS ids do get 16 bits. If correlation matters, a short digest prefix carries it without leaking; if not, plain *** is simpler and the javadoc at :72-74 can say so.
return Hex.encodeHexString(MessageDigest.getInstance("SHA-256").digest(token.getBytes(UTF_8))).substring(0, 8) + "…";- maskToken()/maskTokenId() render an 8-hex SHA-256 prefix ("sha256:983d2944")
instead of the first four characters: every session id starts with the same
"AQIC" header, so the prefix identified nothing, while the digest still lets an
operator holding the token match its log lines.
- AuthInterceptor.accessTokenValid() logs the userinfo claim names only; the body
carries the user's claims (sub, email, ...) whenever the token lacks the profile
scope.
- Repo logs attribute names only in assignService/unassignService/modifyService
(which had four placeholders for five arguments, dropping e.getMessage()) and
filter names only in search; a null-safe names() helper replaces keySet() at the
two round-1 sites as well, since attributes_in may be null.
- Tests pin the call sites, not just the helpers: AuthInterceptorTest asserts the
masked shape in each message and includes logged Throwable messages;
TokenStorageAdapterTest drives update() with a Token whose field read fails
(mockito-core added to the cts test scope); IdRepoTest covers setAttributes,
setBinaryAttributes, the three service methods and search.
|
Round 2 pushed.
|
maximthomas
left a comment
maximthomas
left a comment
There was a problem hiding this comment.
praise: Round 2 closes the call-site gap round 1 asked for, and the digest is the right answer to the constant AQIC prefix.
maskToken()/maskTokenId()emit byte-identicalsha256:<8 hex>for the same input; both tests pin the same vectors (sha256:983d2944,d5989e92,b8150354,null).TokenStorageAdapterTest.updateLogsTheDigestNotTheIdWhenAFieldCannotBeReaddrives the realupdate()to the masked WARN through the pre-setstatic_statement_update, and@Afterresets it;noneMatch(contains(tokenId))goes red on a raw id.IdRepoTestgoes through theIdRepoentry point withuserPassword=s3cretfor all six operations;assertNamesOnlyfails on a value or on auserPassword=map dump alike.Reposervice sites are 5/5 placeholders withnames();AuthInterceptor.accessTokenValidlogsresponse.keySet()and the test assertsdemo@example.comis absent.ExecuteCallbackacknowledged as a follow-up with the wider scope (read / delete / query).
issue (non-blocking): The ExecuteCallback follow-up also has to cover Repo: setAttributes binds every attribute value into the batch that onFailure prints.
openam-cassandra/openam-cassandra-datastore/src/main/java/org/openidentityplatform/openam/cassandra/Repo.java:409-414, :419-424, :431-433; openam-cassandra/openam-cassandra-datastore/src/main/java/org/openidentityplatform/openam/cassandra/ExecuteCallback.java:98-104, :139-143
setAttributes puts .setString("value", value) for each attribute value into a BatchStatement; debugQuery recurses into DefaultBatchStatement and inlines every text column. On a Cassandra timeout / node-down during Membership self-registration or OAuth account creation, the WARN one frame below the new names() line carries all attribute values — userPassword as the SSHA256 hash convert() (:875-899) produced before the bind, everything else (mail, givenName, …) in clear. A debugQuery mask keyed on coreTokenId alone would not touch it; values.value is the only value column in that table, so masking by column name covers Repo in one line:
// ExecuteCallback.debugQuery, text branch
static final Set<String> MASKED = Set.of("coretokenid", "value");
String bound = ((DefaultBoundStatement) statement).getString(c.getName());
String shown = MASKED.contains(c.getName().asInternal().toLowerCase()) ? mask(bound) : bound;
query.value = query.value.replace(":" + c.getName().asInternal(), "'" + shown + "'");Please name Repo / values.value in the follow-up issue; "Repo logs keySet() only" in the description holds for Repo's own line.
issue (non-blocking): search() still logs the filter values on the debug line above the one you changed.
openam-cassandra/openam-cassandra-datastore/src/main/java/org/openidentityplatform/openam/cassandra/Repo.java:653
logger.debug("break search by empty query {} {}: {}", pattern, avPairs, filterEntry) prints avPairs and filterEntry (key=[values]) verbatim whenever an AND search hits an empty intermediate result; :660 is the only search line that moved to names(avPairs). search_failure_logs_filter_names_only cannot reach :653 — it fails at :579 first.
logger.debug("break search by empty query {} {}: {}", pattern, names(avPairs), filterEntry.getKey());Pin: an AND_MOD search with two filter entries whose first entry matches nothing; assert the captured debug line lacks the second entry's value.
issue (non-blocking): Three more Repo log lines drop an argument the same way :748/:776/:805 did.
openam-cassandra/openam-cassandra-datastore/src/main/java/org/openidentityplatform/openam/cassandra/Repo.java:474, :760, :300
:474 and :760 have three placeholders for four arguments, so e.getMessage() never appears; :300 has two placeholders for three arguments plus a Throwable, so attrNames is dropped. Names only, no value at stake — but the operator loses the failure reason on removeAttributes and getAssignedServices.
logger.error("removeAttributes {} {} {}: {}", type, name, attrNames, e.getMessage()); // :474
logger.error("getAssignedServices {} {} {}: {}", type, name, mapOfServicesAndOCs, e.getMessage()); // :760
logger.error("getAttributes {} {} {}", type, name, attrNames, e); // :300issue (non-blocking): The CodeQL check is red at this head, and "Closes #246, #247" will not hold as written.
openam-cassandra/openam-cassandra-datastore/src/main/java/org/openidentityplatform/openam/cassandra/Repo.java:438, :446, :660, :748, :776, :805
On the PR ref CodeQL keeps java/sensitive-log #504 (:446) open and raised a new #505 on :660 — the line changed, so it got a fresh fingerprint; #503 (:438) is dismissed. java/log-injection #498–#502 (:438/:446/:748/:776/:805) are open too. Alerts close by fingerprint, so #246/#247 will close as "fixed" on merge while their sinks reappear as new alerts. Either dismiss #504, #505 and #498–#502 with the round-1 rationale before merging, or reword "Closes" to #243, #252, #270, #271.
suggestion (non-blocking): captureLogs reads the throwable proxy, but no test produces an event that has one.
openam-mcp-server/src/test/java/org/openidentityplatform/openam/mcp/server/security/AuthInterceptorTest.java:78-81; openam-mcp-server/src/main/java/org/openidentityplatform/openam/mcp/server/security/AuthInterceptor.java:115, :221
The only log.warn(…, e) (:115) sits inside tokenValidSeconds, which every log test stubs (:175/:177/:260/:262); :221 has no test. One case through the real tokenValidSeconds makes the branch live and pins that the token id stays out of both the message and the attached exception:
@Test
void tokenValidSeconds_doesNotLogRawTokenId_whenOpenAMFails() {
String tokenId = "AQIC5wM2LY4Sfczn-failing-session-token";
when(restClient.post()).thenThrow(new IllegalStateException("OpenAM unreachable"));
List<String> messages = captureLogs(() -> assertThat(interceptor.tokenValidSeconds(tokenId)).isEqualTo(-1L));
assertThat(messages).anyMatch(m -> m.contains("error getting token properties") && m.contains("OpenAM unreachable"));
assertThat(messages).noneMatch(m -> m.contains(tokenId));
}contains("OpenAM unreachable") passes only through the throwable-proxy branch — the formatted message ends at the colon.
…ents, cover the exception warning - Repo.search: the debug line written when an AND filter finds nothing logged avPairs and the filter entry with values; it now logs the filter names and the entry key. - Repo.removeAttributes / getAssignedServices had three placeholders for four arguments (e.getMessage() dropped) and getAttributes two for three plus the Throwable (attrNames dropped); placeholders restored. - IdRepoTest pins the search break line, the removeAttributes reason and the getAttributes names; the log capture helper no longer requires a failure. - AuthInterceptorTest drives tokenValidSeconds through the real RestClient failure, so the throwable-proxy branch of captureLogs is exercised and the session id is asserted absent from both the message and the exception.
|
Round 3 pushed.
|
maximthomas
left a comment
maximthomas
left a comment
There was a problem hiding this comment.
praise: Round 3 closes everything round 2 asked for, and each pin goes through the production path rather than a helper.
Repo.java:653is pinned through the realANDbreak (IdRepoTest.java:505-514),:474/:300through injected failures (:516-536),AuthInterceptor.java:115through a failingRestClient(AuthInterceptorTest.java:328-337).- Every new assertion fails on the old line by construction —
noneMatch(contains("s3cret")),endsWith("[cn]: boom"),contains("cn"),noneMatch(contains(tokenId))— so the "went red first" claims need no re-run. - CodeQL is clean on the PR ref:
#498-502won't fix,#503-505false positive, each with the SARIF flow in the thread; no opensensitive-log/log-injectionalert remains.
3 participants
Three of our own components wrote credentials into log files:
AuthInterceptorlogged the OpenAM session id at INFO when refreshing a near-expired token (both the username/password and the OAuth paths) and the OAuth2 access token at WARN when/oauth2/userinforejected it.TokenStorageAdapterlogged the whole CTSToken(Token.toString()printscoreTokenIdand every attribute) when a field could not be read duringupdate.Repologged the full attribute map onsetAttributesfailure and insetBinaryAttributes; that map carriesuserPasswordfor Membership self-registration and OAuth account creation.A session id or access token in a log file is enough to hijack the session, so:
AuthInterceptor.maskToken()/TokenStorageAdapter.maskTokenId()keep a 4-character prefix and replace the rest with***(short values become***).RepologskeySet()only.AuthInterceptorTestattaches a logbackListAppenderand asserts the raw tokens never appear in the captured messages (both refresh paths and the invalid-userinfo path); newTokenStorageAdapterTestcovers the mask.Closes CodeQL
java/sensitive-logalerts #243, #246, #247, #252, #270, #271.Review round 2
maskToken()/maskTokenId()render an 8-hex SHA-256 prefix (sha256:983d2944) instead of the first four characters: every session id starts with the sameAQICheader, so the prefix identified nothing, while the digest still lets an operator holding the token match its log lines.AuthInterceptor.accessTokenValid()logs the userinfo claim names only — the body carries the user's claims (sub,email, …) whenever the token lacks theprofilescope.Repologs attribute names only inassignService/unassignService/modifyService(which also had four placeholders for five arguments, droppinge.getMessage()) and filter names only insearch; a null-safenames()helper replaceskeySet()at the two round-1 sites too, sinceattributes_inmay be null.AuthInterceptorTestasserts the masked shape in each message and includes loggedThrowablemessages;TokenStorageAdapterTestdrivesupdate()with aTokenwhose field read fails (mockito-coreadded to the cts test scope);IdRepoTestcoverssetAttributes,setBinaryAttributes, the three service methods andsearch.Not in this PR:
ExecuteCallback.debugQuery()inlines every boundtextcolumn —coreTokenIdincluded — into the WARN written on any Cassandra failure. It lives in the shared datastore module and every CTS statement (read, delete and query, not only update) goes through it, so it is tracked as a separate follow-up.Review round 3
Repo.search: the debug line written when anANDfilter finds nothing (break search by empty query) loggedavPairsand the filter entry with values; it now logs the filter names and the entry key.Repo.removeAttributes/getAssignedServiceshad three placeholders for four arguments (e.getMessage()dropped) andgetAttributestwo for three plus theThrowable(attrNamesdropped); placeholders restored.IdRepoTestpins the search break line (anANDsearch whose first filter matches nothing), theremoveAttributesreason and thegetAttributesnames;AuthInterceptorTestdrivestokenValidSecondsthrough a failingRestClient, so the throwable-proxy branch ofcaptureLogsis exercised and the session id is asserted absent from both the message and the exception.java/sensitive-logFIX disable init DJLDAPv3Repo with empty LDAP_SERVER_LIST #503–Restlet warning about "Pragma" header #505: the taint reaches the lines through the identityname/type/ searchpattern, not the attribute values;java/log-injectionFIX java.lang.UnsupportedClassVersionError: org/openjdk/nashorn/api/scripting/NashornScriptEngineFactory has been compiled by a more recent version of the Java Runtime #498–CTS add cache for persistence level #502: the medium batch).The
ExecuteCallback.debugQuery()follow-up also covers the datastore:Repo.setAttributesbinds every attribute value into the batch thatonFailureprints (values.value), so the mask there has to be keyed oncoreTokenIdandvalue.