improve logging

This commit is contained in:
Jörg Prante 2024-04-22 19:05:26 +02:00
parent 7058cfa211
commit 9baa804bc2
2 changed files with 76 additions and 62 deletions

View file

@ -70,12 +70,16 @@ public class IncomingContextHandler implements HttpHandler {
logger.log(Level.FINE, "found our cookie " + sessionCookieName); logger.log(Level.FINE, "found our cookie " + sessionCookieName);
if (session == null) { if (session == null) {
try { try {
payload = decodeCookie(cookie); // extract payload from our cookie, must be not null, otherwise security problem with exception
logger.log(Level.FINE, "payload from cookie = " + payload); payload = toPayload(cookie);
// extract session from payload and recover session from persistence store
session = toSession(payload); session = toSession(payload);
logger.log(Level.FINE, "session from payload = " + session + " expired = " + session.isExpired() + " valid = " + session.isValid()); // extract user profile from session
userProfile = toUserProfile(session); userProfile = toUserProfile(session);
logger.log(Level.FINE, "userprofile from session = " + userProfile); // do not log explicit content of payload, session, userprofile to not leak sensitive info into log
logger.log(Level.FINE, (payload != null && !payload.isEmpty() ? "payload found" : "no payload") +
(session != null && !session.isEmpty() ? ", session found" : ", no session") +
(userProfile != null && userProfile.getUserId() != null ? ", user profile found (" + userProfile.getUserId() + ")" : ", no user profile"));
} catch (CookieSignatureException e) { } catch (CookieSignatureException e) {
// set exception in context to discard broken cookie later and render exception message // set exception in context to discard broken cookie later and render exception message
context.getAttributes().put("_throwable", e); context.getAttributes().put("_throwable", e);
@ -90,68 +94,18 @@ public class IncomingContextHandler implements HttpHandler {
} }
} }
if (session == null) { if (session == null) {
try { session = newSession(context);
session = sessionCodec.create(sessionIdGenerator.get()); logger.log(Level.FINE, "new session created, id = " + session.id());
logger.log(Level.FINE, "creating new session " + session.id());
} catch (IOException e) {
logger.log(Level.SEVERE, e.getMessage(), e);
throw new HttpException("unable to create new session", context, HttpResponseStatus.INTERNAL_SERVER_ERROR);
}
}
if (userProfile == null) {
logger.log(Level.FINE, "creating new user profile");
userProfile = newUserProfile(payload);
} }
context.getAttributes().put("session", session); context.getAttributes().put("session", session);
if (userProfile == null) {
userProfile = newUserProfile(payload);
logger.log(Level.FINE, "new user profile created");
}
context.getAttributes().put("userprofile", userProfile); context.getAttributes().put("userprofile", userProfile);
} }
protected Session toSession(Map<String, Object> map) { protected Map<String, Object> toPayload(Cookie cookie) throws IOException,
return toSession((String) map.get("id"), map);
}
protected Session toSession(String id, Map<String, Object> map) {
Session session = null;
try {
session = sessionCodec.read(id);
if (session != null && map != null) {
logger.log(Level.FINE, "session id " + id + " restored");
session.putAll(map);
}
} catch (Exception e) {
logger.log(Level.FINEST, "unable to restore session, id = " + id, e);
}
return session;
}
@SuppressWarnings("unchecked")
protected UserProfile toUserProfile(Session session) {
Map<String, Object> map = (Map<String, Object>) session.get("userprofile");
return map != null ? BaseUserProfile.fromMap(map) : null;
}
@SuppressWarnings("unchecked")
protected UserProfile newUserProfile(Map<String, Object> cookieMap) {
UserProfile userProfile = new BaseUserProfile();
// user_id, e_user_id are in cookie map
if (cookieMap != null) {
Map<String, Object> m = (Map<String, Object>) cookieMap.get("map");
if (m == null) {
// nothing found
return userProfile;
}
if (m.containsKey("user_id")) {
userProfile.setUserId((String) m.get("user_id"));
}
if (m.containsKey("e_user_id")) {
userProfile.setEffectiveUserId((String) m.get("e_user_id"));
}
// roles, permissions, attributes must be filled later
}
return userProfile;
}
private Map<String, Object> decodeCookie(Cookie cookie) throws IOException,
NoSuchAlgorithmException, InvalidKeyException, CookieSignatureException { NoSuchAlgorithmException, InvalidKeyException, CookieSignatureException {
PercentDecoder percentDecoder = new PercentDecoder(StandardCharsets.ISO_8859_1.newDecoder() PercentDecoder percentDecoder = new PercentDecoder(StandardCharsets.ISO_8859_1.newDecoder()
.onMalformedInput(CodingErrorAction.IGNORE) .onMalformedInput(CodingErrorAction.IGNORE)
@ -172,4 +126,64 @@ public class IncomingContextHandler implements HttpHandler {
} }
return Map.of("id", id, "payload", payload, "map", CookieSignatureUtil.toMap(payload)); return Map.of("id", id, "payload", payload, "map", CookieSignatureUtil.toMap(payload));
} }
protected Session toSession(Map<String, Object> map) {
if (map == null) {
return null;
}
String id = (String) map.get("id");
Session session = null;
try {
if (id != null) {
session = sessionCodec.read(id);
if (session != null) {
logger.log(Level.FINE, "session id " + id + " restored, valid = " + session.isValid() +
", age = " + session.getAge() + ", expired = " + session.isExpired());
session.putAll(map);
}
}
} catch (Exception e) {
logger.log(Level.FINEST, "unable to restore session id = " + id, e);
}
return session;
}
protected Session newSession(HttpRouterContext context) throws HttpException {
try {
return sessionCodec.create(sessionIdGenerator.get());
} catch (IOException e) {
logger.log(Level.SEVERE, e.getMessage(), e);
throw new HttpException("unable to create new session", context, HttpResponseStatus.INTERNAL_SERVER_ERROR);
}
}
@SuppressWarnings("unchecked")
protected UserProfile toUserProfile(Session session) {
if (session == null) {
return null;
}
Map<String, Object> map = (Map<String, Object>) session.get("userprofile");
return map != null ? BaseUserProfile.fromMap(map) : null;
}
@SuppressWarnings("unchecked")
protected UserProfile newUserProfile(Map<String, Object> cookieMap) {
UserProfile userProfile = new BaseUserProfile();
// user_id, e_user_id are in cookie map
if (cookieMap != null) {
Map<String, Object> m = (Map<String, Object>) cookieMap.get("map");
if (m == null) {
// nothing found
return userProfile;
}
if (m.containsKey("user_id")) {
userProfile.setUserId((String) m.get("user_id"));
}
if (m.containsKey("e_user_id")) {
userProfile.setEffectiveUserId((String) m.get("e_user_id"));
}
// roles, permissions, attributes must be restored later
}
return userProfile;
}
} }

View file

@ -119,7 +119,7 @@ public class OutgoingContextHandler implements HttpHandler {
} }
String id = session.id(); String id = session.id();
if (!session.isValid()) { if (!session.isValid()) {
logger.log(Level.WARNING, "session " + id + " has been invalidated, returning empty cookie"); logger.log(Level.WARNING, "session " + id + " is not invalid, returning empty cookie");
return createEmptyCookie(host, path); return createEmptyCookie(host, path);
} }
if (session.isExpired()) { if (session.isExpired()) {