From b9df5164fa3eafa1ef69070bc329a3ff99b8f92b Mon Sep 17 00:00:00 2001 From: ao508 <15623749+ao508@users.noreply.github.com> Date: Mon, 29 Jul 2024 16:47:34 -0400 Subject: [PATCH] More logging for datadog (#1241) Signed-off-by: Angelica Ochoa <15623749+ao508@users.noreply.github.com> --- .../service/impl/RequestServiceImpl.java | 56 +-------------- .../smile/service/impl/SampleServiceImpl.java | 2 +- .../impl/TempoMessageHandlingServiceImpl.java | 24 ++++--- .../service/util/RequestStatusLogger.java | 69 ------------------- .../org/mskcc/smile/service/SmileTestApp.java | 4 -- .../resources/application.properties.EXAMPLE | 3 - 6 files changed, 16 insertions(+), 142 deletions(-) delete mode 100644 service/src/main/java/org/mskcc/smile/service/util/RequestStatusLogger.java diff --git a/service/src/main/java/org/mskcc/smile/service/impl/RequestServiceImpl.java b/service/src/main/java/org/mskcc/smile/service/impl/RequestServiceImpl.java index a065c0f1..badb7270 100644 --- a/service/src/main/java/org/mskcc/smile/service/impl/RequestServiceImpl.java +++ b/service/src/main/java/org/mskcc/smile/service/impl/RequestServiceImpl.java @@ -27,7 +27,6 @@ import org.mskcc.smile.persistence.neo4j.SmileRequestRepository; import org.mskcc.smile.service.SmileRequestService; import org.mskcc.smile.service.SmileSampleService; -import org.mskcc.smile.service.util.RequestStatusLogger; import org.springframework.beans.factory.annotation.Autowired; import org.springframework.stereotype.Component; import org.springframework.transaction.annotation.Transactional; @@ -47,13 +46,7 @@ public class RequestServiceImpl implements SmileRequestService { @Autowired private SmileSampleService sampleService; - @Autowired - private RequestStatusLogger requestStatusLogger; - private final DateFormat IMPORT_DATE_FORMATTER = initDateFormatter(); - // 24 hours in milliseconds - private final Integer TIME_ADJ_24HOURS_MS = 24 * 60 * 60 * 1000; - private Map loggedExistingRequests = new HashMap<>(); private static final Log LOG = LogFactory.getLog(RequestServiceImpl.class); private final ObjectMapper mapper = new ObjectMapper(); @@ -79,7 +72,6 @@ public Boolean saveRequest(SmileRequest request) throws Exception { requestRepository.save(request); return Boolean.TRUE; } - logDuplicateRequest(request); return Boolean.FALSE; } @@ -99,9 +91,9 @@ public Boolean saveRequestMetadata(SmileRequest request) { StringBuilder builder = new StringBuilder(); builder.append("Failed to update the Request-level metadata for request id: ") .append(request.getIgoRequestId()) - .append("\n\tTotal versions of request metadata -->\n\t\t - before save: ") + .append(" - Total versions of request metadata - before save: ") .append(currentMetadataList.size()) - .append("\n\t\t - after save: ") + .append(" - after save: ") .append(updatedMetadataList.size()); LOG.error(builder.toString()); return Boolean.FALSE; @@ -109,36 +101,6 @@ public Boolean saveRequestMetadata(SmileRequest request) { return Boolean.TRUE; } - /** - * Logs duplicate requests. - * @param request - * @throws IOException - */ - private void logDuplicateRequest(SmileRequest request) throws IOException { - // if request has not been logged before then save request to request logger file - // otherwise check if new timestamp occurs within 24 hours since the last time - // the same request was seen. If it does not then save request to logger file - Date newTimestamp = new Date(); - Boolean logRequest = Boolean.FALSE; - if (!loggedExistingRequests.containsKey(request.getIgoRequestId())) { - loggedExistingRequests.put(request.getIgoRequestId(), newTimestamp); - logRequest = Boolean.TRUE; - } else { - // check if new timestamp occurs within 24 hours of the reference timestamp - // if check does not pass then log the request to the logger file - Date referenceTimestamp = loggedExistingRequests.get(request.getIgoRequestId()); - if (!timestampWithin24Hours(referenceTimestamp, newTimestamp)) { - logRequest = Boolean.TRUE; - loggedExistingRequests.put(request.getIgoRequestId(), newTimestamp); - } - } - - if (logRequest) { - requestStatusLogger.logRequestStatus(request.getRequestJson(), - RequestStatusLogger.StatusType.DUPLICATE_REQUEST); - } - } - @Override public SmileRequest getSmileRequestById(String requestId) throws Exception { SmileRequest request = requestRepository.findRequestById(requestId); @@ -198,20 +160,6 @@ public Boolean updateRequestMetadata(RequestMetadata requestMetadata, Boolean fr return Boolean.FALSE; } - /** - * Returns true if new timestamp occurs within 24 hours of the reference timestamp. - * @param referenceTimestamp - * @param newTimestamp - * @return Boolean - */ - private Boolean timestampWithin24Hours(Date referenceTimestamp, Date newTimestamp) { - // create reference timestamp shifted 24 hours in milliseconds - Calendar adjustedReferenceTimestamp = Calendar.getInstance(); - adjustedReferenceTimestamp.setTime(referenceTimestamp); - adjustedReferenceTimestamp.add(Calendar.MILLISECOND, TIME_ADJ_24HOURS_MS); - return newTimestamp.before(adjustedReferenceTimestamp.getTime()); - } - @Override public Boolean requestHasUpdates(SmileRequest existingRequest, SmileRequest request, Boolean fromLims) throws Exception { diff --git a/service/src/main/java/org/mskcc/smile/service/impl/SampleServiceImpl.java b/service/src/main/java/org/mskcc/smile/service/impl/SampleServiceImpl.java index cd0681b7..7b008163 100644 --- a/service/src/main/java/org/mskcc/smile/service/impl/SampleServiceImpl.java +++ b/service/src/main/java/org/mskcc/smile/service/impl/SampleServiceImpl.java @@ -254,7 +254,7 @@ public Boolean updateSampleMetadata(SampleMetadata sampleMetadata, Boolean fromL SmileRequest request = requestService.getSmileRequestById(sampleMetadata.getIgoRequestId()); if (request == null) { LOG.error("Failed to persist sample metadata updates, " - + "request does not exist " + sampleMetadata.getIgoRequestId()); + + "request does not exist " + sampleMetadata.toString()); return Boolean.FALSE; } LOG.info("Persisting new sample to db: " + sampleMetadata.getPrimaryId()); diff --git a/service/src/main/java/org/mskcc/smile/service/impl/TempoMessageHandlingServiceImpl.java b/service/src/main/java/org/mskcc/smile/service/impl/TempoMessageHandlingServiceImpl.java index d4512a9b..cfb14122 100644 --- a/service/src/main/java/org/mskcc/smile/service/impl/TempoMessageHandlingServiceImpl.java +++ b/service/src/main/java/org/mskcc/smile/service/impl/TempoMessageHandlingServiceImpl.java @@ -123,12 +123,13 @@ public void run() { tempoService.mergeBamCompleteEventBySamplePrimaryId(primaryId, bamComplete); } catch (IncorrectResultSizeDataAccessException e) { - LOG.error("Encountered error while persisting BAM complete " - + "event to database: " + bcEvent.toString(), e); + LOG.error("[TEMPO BAM COMPLETE ERROR] Encountered error while " + + "persisting BAM complete event to database: " + + bcEvent.toString(), e); } } } else { - LOG.error("Sample does not exist by id: " + sampleId); + LOG.error("[TEMPO BAM COMPLETE ERROR] Sample does not exist by id: " + sampleId); } } } catch (InterruptedException e) { @@ -169,12 +170,12 @@ public void run() { tempoService.mergeQcCompleteEventBySamplePrimaryId(primaryId, qcComplete); } catch (IncorrectResultSizeDataAccessException e) { - LOG.error("Encountered error while persisting QC complete " - + "event to database: " + qcEvent.toString(), e); + LOG.error("[TEMPO QC COMPLETE ERROR] Encountered error while persisting " + + "QC complete event to database: " + qcEvent.toString(), e); } } } else { - LOG.error("Sample does not exist by id: " + sampleId); + LOG.error("[TEMPO QC COMPLETE ERROR] Sample does not exist by id: " + sampleId); } } } catch (InterruptedException e) { @@ -225,12 +226,13 @@ public void run() { tempoService.mergeMafCompleteEventBySamplePrimaryId(primaryId, mafComplete); } catch (IncorrectResultSizeDataAccessException e) { - LOG.error("Encountered error while persisting MAF complete " - + "event to database: " + mcEvent.toString(), e); + LOG.error("[TEMPO MAF COMPLETE ERROR] Encountered error while " + + "persisting MAF complete event to database: " + + mcEvent.toString(), e); } } } else { - LOG.error("Sample does not exist by id: " + sampleId); + LOG.error("[TEMPO MAF COMPLETE ERROR] Sample does not exist by id: " + sampleId); } } } catch (InterruptedException e) { @@ -327,8 +329,8 @@ public void run() { LOG.info(builder.toString()); tempoService.updateSampleBilling(billing); } else { - LOG.error("Cannot update billing information for sample that does not exist: " - + billing.getPrimaryId()); + LOG.error("[TEMPO SAMPLE BILLING ERROR] Cannot update billing information for " + + "sample that does not exist: " + billing.getPrimaryId()); } } } catch (InterruptedException e) { diff --git a/service/src/main/java/org/mskcc/smile/service/util/RequestStatusLogger.java b/service/src/main/java/org/mskcc/smile/service/util/RequestStatusLogger.java deleted file mode 100644 index 15f9e62c..00000000 --- a/service/src/main/java/org/mskcc/smile/service/util/RequestStatusLogger.java +++ /dev/null @@ -1,69 +0,0 @@ -package org.mskcc.smile.service.util; - -import java.io.File; -import java.io.IOException; -import java.time.LocalDate; -import java.time.format.DateTimeFormatter; -import org.apache.commons.lang.StringUtils; -import org.mskcc.smile.commons.FileUtil; -import org.springframework.beans.factory.annotation.Autowired; -import org.springframework.beans.factory.annotation.Value; -import org.springframework.stereotype.Component; - -/** - * Class for logging request statuses to the provided - * Request Handling filepath. - * @author ochoaa - */ -@Component -public class RequestStatusLogger { - @Value("${smile.request_handling_failures_filepath}") - private String smileRequestFailuresFilepath; - - @Autowired - private FileUtil fileUtil; - - private File requestStatusLoggerFile; - - private static final String[] REQUEST_LOGGER_FILE_HEADER = new String[]{"DATE", "STATUS", "MESSAGE"}; - - /** - * Request StatusType descriptions: - * - DUPLICATE_REQUEST: a request which already exists in the graph db - * - REQUEST_WITH_MISSING_SAMPLES: a request that came in with no sample metadata - * - CMO_REQUEST_MISSING_REQ_FIELDS: a CMO request with sample metadata - * that is missing required fields (cmoPatientId, baitSet) - * - REQUEST_PARSING_ERROR: json parsing exception thrown - * - CMO_REQUEST_FILTER_SKIPPED_REQUEST: applies if smile server is running - * with the cmoRequestFilter enabled and a non-cmo request is encountered - */ - public enum StatusType { - DUPLICATE_REQUEST, - REQUEST_WITH_MISSING_SAMPLES, - CMO_REQUEST_MISSING_REQ_FIELDS, - REQUEST_PARSING_ERROR, - CMO_REQUEST_FILTER_SKIPPED_REQUEST - } - - /** - * Writes request contents and status to the request status logger file. - * @param message - * @param status - * @throws IOException - */ - public void logRequestStatus(String message, StatusType status) throws IOException { - if (requestStatusLoggerFile == null) { - this.requestStatusLoggerFile = fileUtil.getOrCreateFileWithHeader(smileRequestFailuresFilepath, - StringUtils.join(REQUEST_LOGGER_FILE_HEADER, "\t") + "\n"); - } - String currentDate = LocalDate.now().format(DateTimeFormatter.ISO_LOCAL_DATE); - StringBuilder builder = new StringBuilder(); - builder.append(currentDate) - .append("\t") - .append(status.toString()) - .append("\t") - .append(message) - .append("\n"); - fileUtil.writeToFile(requestStatusLoggerFile, builder.toString()); - } -} diff --git a/service/src/test/java/org/mskcc/smile/service/SmileTestApp.java b/service/src/test/java/org/mskcc/smile/service/SmileTestApp.java index 7687f034..bd9840fc 100644 --- a/service/src/test/java/org/mskcc/smile/service/SmileTestApp.java +++ b/service/src/test/java/org/mskcc/smile/service/SmileTestApp.java @@ -16,7 +16,6 @@ import org.mskcc.smile.service.impl.SampleServiceImpl; import org.mskcc.smile.service.impl.TempoMessageHandlingServiceImpl; import org.mskcc.smile.service.impl.TempoServiceImpl; -import org.mskcc.smile.service.util.RequestStatusLogger; import org.springframework.boot.autoconfigure.SpringBootApplication; import org.springframework.boot.autoconfigure.domain.EntityScan; import org.springframework.boot.test.mock.mockito.MockBean; @@ -68,9 +67,6 @@ public CohortCompleteService cohortCompleteService() { @MockBean public CrdbMappingServiceImpl crdbMappingService; - @MockBean - public RequestStatusLogger requestStatusLogger; - @MockBean public Gateway messagingGateway; diff --git a/src/main/resources/application.properties.EXAMPLE b/src/main/resources/application.properties.EXAMPLE index f13fe8c4..7dbbf35b 100644 --- a/src/main/resources/application.properties.EXAMPLE +++ b/src/main/resources/application.properties.EXAMPLE @@ -73,9 +73,6 @@ smile.correct_cmoptid_topic= # messaging failures filepath smile.publishing_failures_filepath= -# request handling failure filepath -smile.request_handling_failures_filepath= - # tempo topics num.tempo_msg_handler_threads= tempo.wes_bam_complete_topic=