diff --git a/backend/src/main/java/ru/micord/ervu/audit/service/impl/BaseAuditService.java b/backend/src/main/java/ru/micord/ervu/audit/service/impl/BaseAuditService.java index 94520ee..3df2fa1 100644 --- a/backend/src/main/java/ru/micord/ervu/audit/service/impl/BaseAuditService.java +++ b/backend/src/main/java/ru/micord/ervu/audit/service/impl/BaseAuditService.java @@ -1,9 +1,14 @@ package ru.micord.ervu.audit.service.impl; +import java.util.Arrays; +import java.util.List; +import java.util.Objects; import javax.servlet.http.HttpServletRequest; import com.fasterxml.jackson.core.JsonProcessingException; import com.fasterxml.jackson.databind.ObjectMapper; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; import org.springframework.beans.factory.annotation.Value; import org.springframework.context.annotation.Conditional; import org.springframework.stereotype.Service; @@ -26,6 +31,10 @@ import ru.micord.ervu.util.NetworkUtils; @Service @Conditional(AuditEnabledCondition.class) public class BaseAuditService implements AuditService { + private static final Logger LOGGER = LoggerFactory.getLogger(BaseAuditService.class); + private static final List IP_HEADERS = Arrays.asList("X-Forwarded-For", "Proxy-Client-IP", "WL-Proxy-Client-IP", "HTTP_CLIENT_IP", "HTTP_X_FORWARDED_FOR"); + + private final AuditKafkaPublisher auditPublisher; private final JwtTokenService jwtTokenService; private final ObjectMapper objectMapper; @@ -64,10 +73,26 @@ public class BaseAuditService implements AuditService { @Override public void processAuthEvent(HttpServletRequest request, PersonModel personModel, String status, String eventType) { + long startTime = System.currentTimeMillis(); String serverIp = NetworkUtils.getServerIp(); + LOGGER.info("Thread {} - server ip got in {} ms", Thread.currentThread().getId(), + System.currentTimeMillis() - startTime); + + startTime = System.currentTimeMillis(); String clientIp = NetworkUtils.getClientIp(request); + LOGGER.info("Thread {} - client ip got in {} ms", Thread.currentThread().getId(), + System.currentTimeMillis() - startTime); + + startTime = System.currentTimeMillis(); String serverHostName = NetworkUtils.getHostName(serverIp); + LOGGER.info("Thread {} - server host name got in {} ms", Thread.currentThread().getId(), + System.currentTimeMillis() - startTime); + + startTime = System.currentTimeMillis(); String clientHostName = NetworkUtils.getHostName(clientIp); + LOGGER.info("Thread {} - client host name got in {} ms", Thread.currentThread().getId(), + System.currentTimeMillis() - startTime); + startTime = System.currentTimeMillis(); AuditAuthorizationEvent event = new AuditAuthorizationEvent( personModel.getPrnsId(), @@ -85,6 +110,10 @@ public class BaseAuditService implements AuditService { ); String message = convertToMessage(event); auditPublisher.publishEvent(authorizationTopic, message); + LOGGER.info("Thread {} - event published in {} ms", Thread.currentThread().getId(), + System.currentTimeMillis() - startTime); + + LOGGER.info("client ip from header: {}", getClientIp(request)); } @Override @@ -114,4 +143,14 @@ public class BaseAuditService implements AuditService { throw new RuntimeException(e); } } + + public String getClientIp(HttpServletRequest request) { + IP_HEADERS.forEach(header -> LOGGER.info("Data from header: {} - {}", header, request.getHeader(header))); + return IP_HEADERS.stream() + .map(request::getHeader) + .filter(Objects::nonNull) + .filter(ip -> !ip.isEmpty() && !ip.equalsIgnoreCase("unknown")) + .findFirst() + .orElseGet(request::getRemoteAddr); + } } diff --git a/backend/src/main/java/ru/micord/ervu/security/esia/service/EsiaAuthService.java b/backend/src/main/java/ru/micord/ervu/security/esia/service/EsiaAuthService.java index d4054f0..f8793a0 100644 --- a/backend/src/main/java/ru/micord/ervu/security/esia/service/EsiaAuthService.java +++ b/backend/src/main/java/ru/micord/ervu/security/esia/service/EsiaAuthService.java @@ -184,6 +184,7 @@ public class EsiaAuthService { public void authEsiaTokensByCode(String esiaAuthCode, String state, HttpServletResponse response, HttpServletRequest request) { long startReqTime = System.currentTimeMillis(); + long startSubReqTime; String esiaAccessTokenStr = null; String prnOid = null; Long expiresIn = null; @@ -204,9 +205,9 @@ public class EsiaAuthService { parameters.put("state", "%s"); parameters.put("redirect_uri", redirectUrl); parameters.put("code", esiaAuthCode); - long startTime = System.currentTimeMillis(); + startSubReqTime = System.currentTimeMillis(); SignResponse signResponse = signMap(parameters); - signSecret = System.currentTimeMillis() - startTime; + signSecret = System.currentTimeMillis() - startSubReqTime; String newState = signResponse.getState(); String clientSecret = signResponse.getSignature(); String authUrl = esiaConfig.getEsiaBaseUri() + esiaConfig.getEsiaTokenUrl(); @@ -222,7 +223,7 @@ public class EsiaAuthService { .setParameter("token_type", "Bearer") .setParameter("client_certificate_hash", esiaConfig.getClientCertHash()) .toFormUrlencodedString(); - startTime = System.currentTimeMillis(); + startSubReqTime = System.currentTimeMillis(); HttpRequest postReq = HttpRequest.newBuilder(URI.create(authUrl)) .header(HttpHeaders.CONTENT_TYPE, "application/x-www-form-urlencoded") .POST(HttpRequest.BodyPublishers.ofString(postBody)) @@ -232,7 +233,7 @@ public class EsiaAuthService { .connectTimeout(Duration.ofSeconds(esiaConfig.getConnectionTimeout())) .build() .send(postReq, HttpResponse.BodyHandlers.ofString()); - requestAccessToken = System.currentTimeMillis() - startTime; + requestAccessToken = System.currentTimeMillis() - startSubReqTime; String responseString = postResp.body(); EsiaTokenResponse tokenResponse = objectMapper.readValue(responseString, EsiaTokenResponse.class @@ -247,9 +248,9 @@ public class EsiaAuthService { throw new EsiaException("Token invalid. State from request not equals with state from response."); } esiaAccessTokenStr = tokenResponse.getAccessToken(); - startTime = System.currentTimeMillis(); + startSubReqTime = System.currentTimeMillis(); String verifyResult = verifyToken(esiaAccessTokenStr); - verifySecret = System.currentTimeMillis() - startTime; + verifySecret = System.currentTimeMillis() - startSubReqTime; if (verifyResult != null) { throw new EsiaException(verifyResult); } @@ -283,9 +284,11 @@ public class EsiaAuthService { } finally { if (personModel != null) { + startSubReqTime = System.currentTimeMillis(); auditService.processAuthEvent( request, personModel, status, AuditConstants.LOGIN_EVENT_TYPE ); + LOGGER.info("Thread {} - Process auth event: {} ms", Thread.currentThread().getId(), System.currentTimeMillis() - startSubReqTime); } createTokenAndAddCookie(response, prnOid, ervuId, expiresIn); LOGGER.info("Thread {} - Request time: {} ms", Thread.currentThread().getId(), System.currentTimeMillis() - startReqTime);