Fix dcm4che#3646 : Retrieve audit service improvements and fixes

dcm4chee-arc-audit/src/main/java/org/dcm4chee/arc/audit/AuditService.java

@@ -76,6 +76,7 @@
 import org.dcm4chee.arc.retrieve.ExternalRetrieveContext;
 import org.dcm4chee.arc.retrieve.RetrieveContext;
 import org.dcm4chee.arc.stgcmt.StgCmtContext;
+import org.dcm4chee.arc.store.InstanceLocations;
 import org.dcm4chee.arc.store.StoreContext;
 import org.dcm4chee.arc.store.StoreSession;
 import org.dcm4chee.arc.study.StudyMgtContext;
@@ -713,15 +714,27 @@ impaxEndpoint, impaxEndpointHost(impaxEndpoint))
     }
 
     void spoolRetrieve(AuditUtils.EventType eventType, RetrieveContext ctx) {
-        if (ctx.getMatches().size() == 0 && ctx.getCStoreForwards().size() == 0) {
-            LOG.info("Retrieve context has no matches and no C-Store Forwards. Exit spooling retrieve event.");
+        if (ctx.getMatches().isEmpty() && ctx.getCStoreForwards().isEmpty()
+                && (ctx.failed() == 0 || ctx.getFailedMatches().isEmpty())) {
+            LOG.info("Neither matches nor C-Store Forwards nor failed matches present. Exit spooling retrieve event {}",
+                    eventType);
             return;
         }
 
         try {
             RetrieveAuditService retrieveAuditService = new RetrieveAuditService(ctx, getArchiveDevice());
-            for (AuditInfoBuilder[] auditInfoBuilder : retrieveAuditService.getAuditInfoBuilder())
-                writeSpoolFile(eventType, null, auditInfoBuilder);
+            if (ctx.failed() > 0) {
+                Collection<InstanceLocations> failedRetrieves = retrieveAuditService.failedMatches();
+                if (!failedRetrieves.isEmpty())
+                    writeSpoolFile(eventType, null,
+                            retrieveAuditService.createRetrieveFailureAuditInfo(failedRetrieves)
+                                    .toArray(new AuditInfoBuilder[0]));
+            }
+            Collection<InstanceLocations> completedMatches = retrieveAuditService.completedMatches();
+            if (!completedMatches.isEmpty())
+                writeSpoolFile(eventType, null,
+                        retrieveAuditService.createRetrieveSuccessAuditInfo(completedMatches)
+                                .toArray(new AuditInfoBuilder[0]));
         } catch (Exception e) {
             LOG.info("Failed to spool Retrieve of [StudyIUID={}]\n", ctx.getStudyInstanceUID(), e);
         }

dcm4chee-arc-audit/src/main/java/org/dcm4chee/arc/audit/AuditUtils.java

@@ -339,6 +339,14 @@ static EventType forQueueEvent(TaskOperation operation) {
                     : operation == TaskOperation.RescheduleTasks
                         ? RESCHD_TSK : DELETE_TSK;
         }
+
+        @Override
+        public String toString() {
+            return "Audit Event Type[EventID = " + eventID +
+                    ", EventActionCode = " + eventActionCode +
+                    ", EventTypeCode = " + eventTypeCode +
+                    "]";
+        }
     }
 
     static String findScpHost(String findScp, IApplicationEntityCache aeCache) {

dcm4chee-arc-audit/src/main/java/org/dcm4chee/arc/audit/RetrieveAuditService.java

@@ -49,9 +49,12 @@
 import org.dcm4chee.arc.keycloak.HttpServletRequestInfo;
 import org.dcm4chee.arc.store.InstanceLocations;
 import org.dcm4chee.arc.retrieve.RetrieveContext;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
 
 import java.nio.file.Path;
 import java.util.*;
+import java.util.stream.Collectors;
 
 /**
  * @author Vrinda Nayak <[email protected]>
@@ -60,79 +63,90 @@
  */
 
 class RetrieveAuditService {
-
+    private final static Logger LOG = LoggerFactory.getLogger(RetrieveAuditService.class);
     private final RetrieveContext ctx;
     private final ArchiveDeviceExtension arcDev;
-    private HttpServletRequestInfo httpServletRequestInfo;
-    private AuditInfoBuilder[][] auditInfoBuilder;
+    private final HttpServletRequestInfo httpServletRequestInfo;
+    private final String warningMsg;
+    private final String failureMsg;
 
     RetrieveAuditService(RetrieveContext ctx, ArchiveDeviceExtension arcDev) {
         this.ctx = ctx;
         this.arcDev = arcDev;
-        httpServletRequestInfo = ctx.getHttpServletRequestInfo();
-        processRetrieve();
+        this.httpServletRequestInfo = ctx.getHttpServletRequestInfo();
+        this.warningMsg = warningMsg();
+        this.failureMsg = failureMsg();
     }
 
-    private void processRetrieve() {
-        if (someInstancesRetrieveFailed())
-            processPartialRetrieve();
-        else {
-            auditInfoBuilder = new AuditInfoBuilder[1][];
-            auditInfoBuilder[0] = buildAuditInfos(toBuildAuditInfo(true), ctx.getMatches());
+    Collection<InstanceLocations> failedMatches() {
+        if (ctx.getFailedMatches().isEmpty()) {
+            List<String> failedSOPIUIDs = Arrays.asList(ctx.failedSOPInstanceUIDs());
+            List<InstanceLocations> failedMatches = ctx.getMatches().stream()
+                                                        .filter(il -> failedSOPIUIDs.contains(il.getSopInstanceUID()))
+                                                        .collect(Collectors.toList());
+            if (failedMatches.isEmpty())
+                LOG.info("Instance information not available for instances failed to be retrieved {}. Exit spooling of retrieve failures",
+                        failedSOPIUIDs);
+
+            return failedMatches;
         }
+        return ctx.getFailedMatches();
     }
 
-    private void processPartialRetrieve() {
-        auditInfoBuilder = new AuditInfoBuilder[2][];
-        HashSet<InstanceLocations> failed = new HashSet<>();
-        List<String> failedList = Arrays.asList(ctx.failedSOPInstanceUIDs());
-        HashSet<InstanceLocations> success = new HashSet<>(ctx.getMatches());
-        ctx.getMatches().forEach(instanceLocation -> {
-            if (failedList.contains(instanceLocation.getSopInstanceUID())) {
-                failed.add(instanceLocation);
-                success.remove(instanceLocation);
-            }
-        });
-        auditInfoBuilder[0] = buildAuditInfos(toBuildAuditInfo(true), failed);
-        auditInfoBuilder[1] = buildAuditInfos(toBuildAuditInfo(false), success);
+    Collection<InstanceLocations> completedMatches() {
+        List<String> failedSOPIUIDs = Arrays.asList(ctx.failedSOPInstanceUIDs());
+        return ctx.getMatches().stream()
+                .filter(il -> !failedSOPIUIDs.contains(il.getSopInstanceUID()))
+                .collect(Collectors.toList());
     }
 
-    private AuditInfoBuilder[] buildAuditInfos(AuditInfoBuilder auditInfoBuilder, Collection<InstanceLocations> il) {
-        LinkedHashSet<AuditInfoBuilder> objs = new LinkedHashSet<>();
-        objs.add(auditInfoBuilder);
-        objs.addAll(buildInstanceInfos(ctx.getCStoreForwards()));
-        objs.addAll(buildInstanceInfos(il));
-        return objs.toArray(new AuditInfoBuilder[0]);
+    List<AuditInfoBuilder> createRetrieveSuccessAuditInfo(Collection<InstanceLocations> completedRetrieves) {
+        List<AuditInfoBuilder> retrieveSuccess = new ArrayList<>();
+        retrieveSuccess.add(createCompletedRetrieveInfo());
+        ctx.getCStoreForwards().forEach(cStoreFwd -> retrieveSuccess.add(createInstanceAuditInfo(cStoreFwd)));
+        completedRetrieves.forEach(completedRetrieve -> retrieveSuccess.add(createInstanceAuditInfo(completedRetrieve)));
+        return retrieveSuccess;
     }
 
-    private LinkedHashSet<AuditInfoBuilder> buildInstanceInfos(Collection<InstanceLocations> instanceLocations) {
-        LinkedHashSet<AuditInfoBuilder> objs = new LinkedHashSet<>();
-        instanceLocations.forEach(instanceLocation -> {
-            Attributes attrs = instanceLocation.getAttributes();
-            AuditInfoBuilder iI = new AuditInfoBuilder.Builder()
-                    .studyUIDAccNumDate(attrs, arcDev)
-                    .sopCUID(attrs.getString(Tag.SOPClassUID))
-                    .sopIUID(attrs.getString(Tag.SOPInstanceUID))
-                    .pIDAndName(attrs, arcDev)
-                    .build();
-            objs.add(iI);
-        });
-        return objs;
+    private AuditInfoBuilder createCompletedRetrieveInfo() {
+        AuditInfoBuilder.Builder retrieveInfo = new AuditInfoBuilder.Builder();
+        retrieveInfo.warning(warningMsg);
+        return addUserParticipantDetails(retrieveInfo);
+    }
+
+    List<AuditInfoBuilder> createRetrieveFailureAuditInfo(Collection<InstanceLocations> failedRetrieves) {
+        List<AuditInfoBuilder> retrieveFailure = new ArrayList<>();
+        retrieveFailure.add(createFailedRetrieveInfo());
+        ctx.getCStoreForwards().forEach(cStoreFwd -> retrieveFailure.add(createInstanceAuditInfo(cStoreFwd)));
+        failedRetrieves.forEach(failedRetrieve -> retrieveFailure.add(createInstanceAuditInfo(failedRetrieve)));
+        return retrieveFailure;
     }
 
-    private AuditInfoBuilder toBuildAuditInfo(boolean checkForFailures) {
-        AuditInfoBuilder.Builder infoBuilder = new AuditInfoBuilder.Builder()
-                .warning(warning())
-                .outcome(checkForFailures ? outcome() : null)
-                .failedIUIDShow(isFailedIUIDShow(checkForFailures));
+    private AuditInfoBuilder createFailedRetrieveInfo() {
+        AuditInfoBuilder.Builder retrieveInfo = new AuditInfoBuilder.Builder();
+        retrieveInfo.outcome(outcomeDesc());
+        retrieveInfo.failedIUIDShow(true);
+        return addUserParticipantDetails(retrieveInfo);
+    }
 
+    private AuditInfoBuilder addUserParticipantDetails(AuditInfoBuilder.Builder retrieveInfo) {
         return isExportTriggered(ctx)
                 ? httpServletRequestInfo != null
-                    ? restfulTriggeredExport(infoBuilder)
-                    : schedulerTriggeredExport(infoBuilder)
+                    ? restfulTriggeredExport(retrieveInfo)
+                    : schedulerTriggeredExport(retrieveInfo)
                 : httpServletRequestInfo != null
-                    ? rad69OrWadoRS(infoBuilder)
-                    : cMoveCGet(infoBuilder);
+                    ? rad69OrWadoRS(retrieveInfo)
+                    : cMoveCGet(retrieveInfo);
+    }
+
+    private AuditInfoBuilder createInstanceAuditInfo(InstanceLocations il) {
+        Attributes attrs = il.getAttributes();
+        return new AuditInfoBuilder.Builder()
+                .studyUIDAccNumDate(attrs, arcDev)
+                .sopCUID(attrs.getString(Tag.SOPClassUID))
+                .sopIUID(attrs.getString(Tag.SOPInstanceUID))
+                .pIDAndName(attrs, arcDev)
+                .build();
     }
 
     private AuditInfoBuilder cMoveCGet(AuditInfoBuilder.Builder infoBuilder) {
@@ -174,46 +188,35 @@ private AuditInfoBuilder restfulTriggeredExport(AuditInfoBuilder.Builder infoBui
             .build();
     }
 
-    private boolean isFailedIUIDShow(boolean checkForFailures) {
-        return checkForFailures && (allInstancesRetrieveFailed() || someInstancesRetrieveFailed());
-    }
-
     private boolean isExportTriggered(RetrieveContext ctx) {
         return (ctx.getRequestAssociation() == null && ctx.getStoreAssociation() != null)
                 || (ctx.getRequestAssociation() == null && ctx.getStoreAssociation() == null && ctx.getException() != null);
     }
 
-    private boolean someInstancesRetrieveFailed() {
-        return ctx.failedSOPInstanceUIDs().length != ctx.getMatches().size() && ctx.failedSOPInstanceUIDs().length > 0;
-    }
-
-    private boolean allInstancesRetrieveCompleted() {
-        return (ctx.failedSOPInstanceUIDs().length == 0 && !ctx.getMatches().isEmpty())
-                || (ctx.getMatches().isEmpty() && !ctx.getCStoreForwards().isEmpty());
-    }
-
-    private boolean allInstancesRetrieveFailed() {
-        return ctx.failedSOPInstanceUIDs().length == ctx.getMatches().size() && !ctx.getMatches().isEmpty();
+    private String warningMsg() {
+        return ctx.warning() > 0
+                ? "Warnings on retrieve of " + ctx.warning() + " instances"
+                : null;
     }
 
-    private String warning() {
-        return allInstancesRetrieveCompleted() && ctx.warning() != 0
-                ? ctx.warning() == ctx.getMatches().size()
-                    ? "Warnings on retrieve of all instances"
-                    : "Warnings on retrieve of " + ctx.warning() + " instances"
+    private String failureMsg() {
+        return ctx.failed() > 0 || !ctx.getFailedMatches().isEmpty()
+                ? "Retrieve of " + ctx.failed() + " objects failed"
                 : null;
     }
 
-    private String outcome() {
-        return ctx.getException() != null
-                ? ctx.getException().getMessage() != null
-                    ? ctx.getException().getMessage()
-                    : ctx.getException().toString()
-                : allInstancesRetrieveFailed()
-                    ? "Unable to perform sub-operations on all instances"
-                    : someInstancesRetrieveFailed()
-                        ? "Retrieve of " + ctx.failed() + " objects failed"
-                        : null;
+    private String outcomeDesc() {
+        if (warningMsg == null && failureMsg == null && ctx.getException() == null)
+            return null;
+
+        StringBuilder sb = new StringBuilder();
+        if (warningMsg != null)
+            sb.append(warningMsg).append("\n");
+        if (failureMsg != null)
+            sb.append(failureMsg).append("\n");
+        if (ctx.getException() != null)
+            sb.append(ctx.getException().toString()).append("\n");
+        return sb.toString();
     }
 
     static AuditMessage auditMsg(AuditLogger auditLogger, Path path, AuditUtils.EventType eventType) {
@@ -350,8 +353,4 @@ private static AuditMessages.UserIDTypeCode archiveUserIDTypeCode(String userID)
     private static String getLocalHostName(AuditLogger auditLogger) {
         return auditLogger.getConnections().get(0).getHostname();
     }
-
-    AuditInfoBuilder[][] getAuditInfoBuilder() {
-        return auditInfoBuilder;
-    }
 }

dcm4chee-arc-export-storage/src/main/java/org/dcm4che/arc/export/storage/StorageExporter.java

@@ -139,7 +139,7 @@ public Outcome export(ExportContext exportContext) throws Exception {
                     } catch (Exception e) {
                         LOG.warn("Failed to copy {} to {}:\n", instanceLocations, storage.getStorageDescriptor(), e);
                         retrieveContext.incrementFailed();
-                        retrieveContext.addFailedSOPInstanceUID(instanceLocations.getSopInstanceUID());
+                        retrieveContext.addFailedMatch(instanceLocations);
                         if (location != null)
                             try {
                                 storage.revokeStorage(writeCtx);

dcm4chee-arc-retrieve/src/main/java/org/dcm4chee/arc/retrieve/RetrieveContext.java

@@ -206,6 +206,10 @@ public interface RetrieveContext extends Closeable {
 
     String[] failedSOPInstanceUIDs();
 
+    void addFailedMatch(InstanceLocations match);
+
+    Collection<InstanceLocations> getFailedMatches();
+
     int remaining();
 
     int status();

dcm4chee-arc-retrieve/src/main/java/org/dcm4chee/arc/retrieve/impl/RetrieveContextImpl.java

@@ -105,6 +105,8 @@ class RetrieveContextImpl implements RetrieveContext {
             Collections.synchronizedCollection(new ArrayList<InstanceLocations>());
     private final Collection<String> failedSOPInstanceUIDs =
             Collections.synchronizedCollection(new ArrayList<String>());
+    private final Collection<InstanceLocations> failedMatches =
+            Collections.synchronizedCollection(new ArrayList<InstanceLocations>());
     private final HashMap<String, Storage> storageMap = new HashMap<>();
     private ScheduledFuture<?> writePendingRSP;
     private volatile Attributes fallbackMoveRSPCommand;
@@ -504,6 +506,17 @@ public String[] failedSOPInstanceUIDs() {
         return dest;
     }
 
+    @Override
+    public void addFailedMatch(InstanceLocations match) {
+        failedSOPInstanceUIDs.add(match.getSopInstanceUID());
+        failedMatches.add(match);
+    }
+
+    @Override
+    public Collection<InstanceLocations> getFailedMatches() {
+        return failedMatches;
+    }
+
     @Override
     public int remaining() {
          return Math.max(0,
@@ -531,10 +544,10 @@ public String getOutcomeDescription() {
         return (failed() == 0 && warning() == 0)
                 ? "Success"
                 : (completed() == 0 && warning() == 0)
-                ? "Unable to perform sup-operations"
-                : (failed() == 0)
-                ? "Warnings on retrieve of " + warning() + " objects"
-                : "Retrieve of " + failed() + " objects failed";
+                    ? "Unable to perform sup-operations"
+                    : (failed() == 0)
+                        ? "Warnings on retrieve of " + warning() + " objects"
+                        : "Retrieve of " + failed() + " objects failed";
 
     }
 

dcm4chee-arc-retrieve/src/main/java/org/dcm4chee/arc/retrieve/impl/RetrieveServiceImpl.java

@@ -646,7 +646,7 @@ public boolean restrictRetrieveAccordingTransferCapabilities(RetrieveContext ctx
                     ctx.decrementNumberOfMatches();
                 } else {
                     ctx.incrementFailed();
-                    ctx.addFailedSOPInstanceUID(match.getSopInstanceUID());
+                    ctx.addFailedMatch(match);
                 }
                 LOG.info("{}: failed to send {} to {} - no Presentation Context offered",
                         ctx.getRequestAssociation(), match, ctx.getDestinationAETitle());

dcm4chee-arc-store-scu/src/main/java/org/dcm4chee/arc/store/scu/impl/CStoreForwardTask.java

@@ -151,7 +151,7 @@ private void store(StoreContext storeCtx) {
             }
         } catch (Exception e) {
             ctx.incrementFailed();
-            ctx.addFailedSOPInstanceUID(iuid);
+            ctx.addFailedMatch(inst);
             LOG.info("{}: failed to send {} to {}:", rqas, inst, ctx.getDestinationAETitle(), e);
         }
     }
@@ -208,7 +208,7 @@ public void onDimseRSP(Association as, Attributes cmd, Attributes data) {
                 ctx.incrementWarning();
             } else {
                 ctx.incrementFailed();
-                ctx.addFailedSOPInstanceUID(inst.getSopInstanceUID());
+                ctx.addFailedMatch(inst);
             }
         }
     }

dcm4chee-arc-store-scu/src/main/java/org/dcm4chee/arc/store/scu/impl/CStoreSCUImpl.java

@@ -93,7 +93,7 @@ private Association openAssociation(RetrieveContext ctx)
                     if (storeas.getTransferSyntaxesFor(inst.getSopClassUID()).isEmpty()) {
                         iter.remove();
                         ctx.incrementFailed();
-                        ctx.addFailedSOPInstanceUID(inst.getSopInstanceUID());
+                        ctx.addFailedMatch(inst);
                         LOG.info("{}: failed to send {} to {} - no Presentation Context accepted",
                                 ctx.getRequestAssociation(), inst, ctx.getDestinationAETitle());
                     }