Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Fix #400: Improve logging #402

Merged
merged 1 commit into from
Sep 29, 2022
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
Expand Up @@ -55,17 +55,13 @@ public CommonOnboardingService(final OnboardingProcessRepository onboardingProce
* @throws OnboardingProcessException Thrown when onboarding process is not found.
*/
public OnboardingProcessEntity findProcess(String processId) throws OnboardingProcessException {
Optional<OnboardingProcessEntity> processOptional = onboardingProcessRepository.findById(processId);
if (processOptional.isEmpty()) {
logger.warn("Onboarding process not found, process ID: {}", processId);
throw new OnboardingProcessException();
}
return processOptional.get();
return onboardingProcessRepository.findById(processId).orElseThrow(() ->
new OnboardingProcessException("Onboarding process not found, process ID: " + processId));
}

/**
* Find an onboarding process.
* @param activationId Acitivation identitfier.
* @param activationId Activation identifier.
* @return Onboarding process.
* @throws OnboardingProcessException Thrown when onboarding process is not found.
*/
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -86,12 +86,8 @@ public OtpVerifyResponse verifyOtpCode(String processId, OwnerId ownerId, String
}
OnboardingProcessEntity process = processOptional.get();

Optional<OnboardingOtpEntity> otpOptional = onboardingOtpRepository.findLastOtp(processId, otpType);
if (otpOptional.isEmpty()) {
logger.warn("Onboarding OTP not found, process ID: {}", processId);
throw new OnboardingProcessException();
}
OnboardingOtpEntity otp = otpOptional.get();
final OnboardingOtpEntity otp = onboardingOtpRepository.findLastOtp(processId, otpType).orElseThrow(() ->
new OnboardingProcessException("Onboarding OTP not found, process ID: " + processId));

// Verify OTP code
final Date now = ownerId.getTimestamp();
Expand Down Expand Up @@ -199,12 +195,9 @@ private OnboardingProcessEntity failProcessOrIdentityVerification(OnboardingProc
} catch (RemoteCommunicationException | IdentityVerificationException | OnboardingProcessLimitException | OnboardingProcessException ex) {
logger.error("Identity verification reset failed, error: {}", ex.getMessage(), ex);
// Obtain most current process entity, the process may have failed due to reached limit of identity verification resets
Optional <OnboardingProcessEntity> updatedProcessOptional = onboardingProcessRepository.findById(process.getId());
if (updatedProcessOptional.isEmpty()) {
logger.warn("Onboarding process not found, process ID: {}", process.getId());
throw new OnboardingProcessException();
}
process = updatedProcessOptional.get();
final String processId = process.getId();
process = onboardingProcessRepository.findById(processId).orElseThrow(() ->
new OnboardingProcessException("Onboarding process not found, process ID: " + processId));
}
} else {
// Fail onboarding process completely
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -96,7 +96,7 @@ public void checkIdentityVerificationLimit(OwnerId ownerId) throws RemoteCommuni
&& verification.getStatus() != IdentityVerificationStatus.REJECTED)
.forEach(verification -> {
verification.setStatus(IdentityVerificationStatus.FAILED);
logger.info("Switched to {}/FAILED; process ID: {}", verification.getPhase(), verification.getProcessId());
logger.info("Switched to {}/FAILED; {}", verification.getPhase(), ownerId);
});
identityVerificationRepository.saveAll(identityVerifications);

Expand Down Expand Up @@ -132,7 +132,7 @@ public void checkDocumentUploadLimit(OwnerId ownerId, IdentityVerificationEntity
identityVerification.setTimestampLastUpdated(ownerId.getTimestamp());
identityVerification.setTimestampFailed(ownerId.getTimestamp());
identityVerificationRepository.save(identityVerification);
logger.info("Switched to {}/FAILED; process ID: {}", identityVerification.getPhase(), identityVerification.getProcessId());
logger.info("Switched to {}/FAILED; {}", identityVerification.getPhase(), ownerId);
resetIdentityVerification(ownerId);
logger.warn("Max failed attempts reached for document upload, {}.", ownerId);
throw new IdentityVerificationLimitException("Max failed attempts reached for document upload");
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -493,7 +493,7 @@ public ObjectResponse<OtpVerifyResponse> verifyOtp(@EncryptedRequestBody ObjectR
try {
stateMachineService.processStateMachineEvent(ownerId, processId, OnboardingEvent.EVENT_NEXT_STATE);
} catch (IdentityVerificationException e) {
throw new OnboardingProcessException("Unable to move state machine for process ID: " + processId, e);
throw new OnboardingProcessException("Unable to move state machine for " + ownerId, e);
}

return new ObjectResponse<>(otpVerifyResponse);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -26,9 +26,9 @@
import com.wultra.app.onboardingserver.common.database.entity.DocumentVerificationEntity;
import com.wultra.app.onboardingserver.common.database.entity.IdentityVerificationEntity;
import com.wultra.app.onboardingserver.configuration.IdentityVerificationConfig;
import com.wultra.app.onboardingserver.provider.OnboardingProvider;
import com.wultra.app.onboardingserver.provider.model.request.EvaluateClientRequest;
import com.wultra.app.onboardingserver.provider.model.response.EvaluateClientResponse;
import com.wultra.app.onboardingserver.provider.OnboardingProvider;
import lombok.extern.slf4j.Slf4j;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.stereotype.Service;
Expand All @@ -39,7 +39,6 @@

import java.time.Duration;
import java.util.Date;
import java.util.UUID;
import java.util.function.Consumer;

/**
Expand Down Expand Up @@ -90,15 +89,16 @@ public void initClientEvaluation(final OwnerId ownerId, final IdentityVerificati
idVerification.setPhase(IdentityVerificationPhase.CLIENT_EVALUATION);
idVerification.setStatus(IdentityVerificationStatus.IN_PROGRESS);
idVerification.setTimestampLastUpdated(ownerId.getTimestamp());
logger.info("Switched to CLIENT_EVALUATION/IN_PROGRESS; process ID: {}, {}", idVerification.getProcessId(), ownerId);
logger.info("Switched to CLIENT_EVALUATION/IN_PROGRESS; {}", ownerId);
}

/**
* Process client evaluation of the given identity verification initialized in {@link #initClientEvaluation(OwnerId, IdentityVerificationEntity)}.
*
* @param identityVerification identity verification to process
* @param ownerId Owner identification.
*/
public void processClientEvaluation(final IdentityVerificationEntity identityVerification) {
public void processClientEvaluation(final IdentityVerificationEntity identityVerification, final OwnerId ownerId) {
logger.debug("Evaluating client for {}", identityVerification);

final EvaluateClientRequest request = EvaluateClientRequest.builder()
Expand All @@ -108,8 +108,8 @@ public void processClientEvaluation(final IdentityVerificationEntity identityVer
.verificationId(getVerificationId(identityVerification))
.build();

final Consumer<EvaluateClientResponse> successConsumer = createSuccessConsumer(identityVerification);
final Consumer<Throwable> errorConsumer = createErrorConsumer(identityVerification);
final Consumer<EvaluateClientResponse> successConsumer = createSuccessConsumer(identityVerification, ownerId);
final Consumer<Throwable> errorConsumer = createErrorConsumer(identityVerification, ownerId);
final int maxFailedAttempts = config.getClientEvaluationMaxFailedAttempts();
onboardingProvider.evaluateClient(request)
.retryWhen(Retry.backoff(maxFailedAttempts, Duration.ofSeconds(2)))
Expand All @@ -123,21 +123,21 @@ private static String getVerificationId(final IdentityVerificationEntity identit
.orElseThrow(() -> new IllegalStateException("No document verification for " + identityVerification));
}

private Consumer<EvaluateClientResponse> createSuccessConsumer(final IdentityVerificationEntity identityVerification) {
private Consumer<EvaluateClientResponse> createSuccessConsumer(final IdentityVerificationEntity identityVerification, final OwnerId ownerId) {
return response -> {
final Date now = new Date();
identityVerification.setTimestampLastUpdated(now);
// The timestampFinished parameter is not set yet, there may be other steps ahead
if (response.isAccepted()) {
logger.info("Client evaluation accepted for {}", identityVerification);
identityVerification.setStatus(IdentityVerificationStatus.ACCEPTED);
logger.info("Switched to {}/ACCEPTED; process ID: {}", identityVerification.getPhase(), identityVerification.getProcessId());
logger.info("Switched to {}/ACCEPTED; {}", identityVerification.getPhase(), ownerId);
} else {
logger.info("Client evaluation rejected for {}", identityVerification);
identityVerification.setStatus(IdentityVerificationStatus.REJECTED);
identityVerification.getDocumentVerifications()
.forEach(it -> it.setStatus(DocumentStatus.REJECTED));
logger.info("Switched to {}/REJECTED; process ID: {}", identityVerification.getPhase(), identityVerification.getProcessId());
logger.info("Switched to {}/REJECTED; {}", identityVerification.getPhase(), ownerId);
identityVerification.setTimestampFailed(now);
}
if (response.isErrorOccurred()) {
Expand All @@ -149,7 +149,7 @@ private Consumer<EvaluateClientResponse> createSuccessConsumer(final IdentityVer
};
}

private Consumer<Throwable> createErrorConsumer(final IdentityVerificationEntity identityVerification) {
private Consumer<Throwable> createErrorConsumer(final IdentityVerificationEntity identityVerification, final OwnerId ownerId) {
return t -> {
logger.warn("Client evaluation failed for {} - {}", identityVerification, t.getMessage());
logger.debug("Client evaluation failed for {}", identityVerification, t);
Expand All @@ -159,7 +159,7 @@ private Consumer<Throwable> createErrorConsumer(final IdentityVerificationEntity
final Date now = new Date();
identityVerification.setTimestampLastUpdated(now);
identityVerification.setTimestampFailed(now);
logger.info("Switched to {}/FAILED; process ID: {}", identityVerification.getPhase(), identityVerification.getProcessId());
logger.info("Switched to {}/FAILED; {}", identityVerification.getPhase(), ownerId);
saveInTransaction(identityVerification);
};
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -86,7 +86,7 @@ public IdentityVerificationEntity createIdentityVerification(OwnerId ownerId, St
entity.setUserId(ownerId.getUserId());
entity.setProcessId(processId);

logger.info("Switched to DOCUMENT_UPLOAD/IN_PROGRESS; process ID: {}", processId);
logger.info("Switched to DOCUMENT_UPLOAD/IN_PROGRESS; {}", ownerId);

return identityVerificationRepository.save(entity);
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -113,14 +113,15 @@ public void resendOtp(IdentityVerificationEntity identityVerification) throws On
/**
* Sends an OTP code for a process during identity verification.
* @param identityVerification Identity verification entity.
* @param ownerId Owner identification.
* @throws OnboardingProcessException Thrown when OTP code could not be generated.
* @throws OnboardingOtpDeliveryException Thrown when OTP code could not be sent.
*/
@Transactional
public void sendOtp(IdentityVerificationEntity identityVerification) throws OnboardingProcessException, OnboardingOtpDeliveryException {
public void sendOtp(IdentityVerificationEntity identityVerification, OwnerId ownerId) throws OnboardingProcessException, OnboardingOtpDeliveryException {
identityVerification.setPhase(IdentityVerificationPhase.OTP_VERIFICATION);
identityVerification.setStatus(IdentityVerificationStatus.VERIFICATION_PENDING);
logger.info("Switched to OTP_VERIFICATION/VERIFICATION_PENDING; process ID: {}", identityVerification.getProcessId());
logger.info("Switched to OTP_VERIFICATION/VERIFICATION_PENDING; {}", ownerId);
sendOtpCode(identityVerification.getProcessId(), false);
}

Expand Down Expand Up @@ -150,7 +151,7 @@ public OtpVerifyResponse verifyOtpCode(String processId, OwnerId ownerId, String
logger.info("SCA failed, wrong OTP code, process ID: {}", processId);
return response;
}
return verifyPresenceCheck(process, response);
return verifyPresenceCheck(process, response, ownerId);
}

/**
Expand All @@ -165,7 +166,7 @@ public boolean isUserVerifiedUsingOtp(String processId) {
.isPresent();
}

private OtpVerifyResponse verifyPresenceCheck(final OnboardingProcessEntity process, final OtpVerifyResponse response) throws OnboardingProcessException {
private OtpVerifyResponse verifyPresenceCheck(final OnboardingProcessEntity process, final OtpVerifyResponse response, final OwnerId ownerId) throws OnboardingProcessException {
final String processId = process.getId();
if (!identityVerificationConfig.isPresenceCheckEnabled()) {
logger.debug("Presence check is not enabled, process ID: {}", processId);
Expand All @@ -181,11 +182,11 @@ private OtpVerifyResponse verifyPresenceCheck(final OnboardingProcessEntity proc
final RejectOrigin rejectOrigin = idVerification.getRejectOrigin();

if (errorOrigin == ErrorOrigin.PRESENCE_CHECK || rejectOrigin == RejectOrigin.PRESENCE_CHECK) {
logger.info("SCA failed, identity verification ID: {} of process ID: {} contains errorDetail: {}, rejectReason: {} from previous step",
idVerification.getId(), processId, errorDetail, rejectReason);
return moveToPhasePresenceCheck(process, response, idVerification);
logger.info("SCA failed, identity verification ID: {}, {} contains errorDetail: {}, rejectReason: {} from previous step",
idVerification.getId(), ownerId, errorDetail, rejectReason);
return moveToPhasePresenceCheck(process, response, idVerification, ownerId);
} else {
logger.debug("PRESENCE_CHECK without error or reject origin, process ID: {}", idVerification.getProcessId());
logger.debug("PRESENCE_CHECK without error or reject origin, {}", ownerId);
}
return response;
}
Expand All @@ -198,7 +199,8 @@ private IdentityVerificationEntity getIdentityVerificationEntity(final Onboardin
private OtpVerifyResponse moveToPhasePresenceCheck(
final OnboardingProcessEntity process,
final OtpVerifyResponse response,
final IdentityVerificationEntity idVerification) throws OnboardingProcessException {
final IdentityVerificationEntity idVerification,
final OwnerId ownerId) throws OnboardingProcessException {

idVerification.setPhase(PRESENCE_CHECK);
idVerification.setStatus(IdentityVerificationStatus.NOT_INITIALIZED);
Expand All @@ -209,7 +211,7 @@ private OtpVerifyResponse moveToPhasePresenceCheck(
idVerification.setRejectOrigin(null);
identityVerificationRepository.save(idVerification);

logger.info("Switched to PRESENCE_CHECK/NOT_INITIALIZED; process ID: {}", idVerification.getProcessId());
logger.info("Switched to PRESENCE_CHECK/NOT_INITIALIZED; {}", ownerId);

markVerificationOtpAsFailed(process.getId());

Expand Down
Loading