SUPPORT-9182: add extra logs

This commit is contained in:
gulnaz 2025-05-30 12:33:09 +03:00
parent 40fecd062f
commit e846562f0c
2 changed files with 48 additions and 6 deletions

View file

@ -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<String> 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);
}
}

View file

@ -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);