Log async upload job details correlated with operation id

multiapps-controller-persistence/src/main/java/org/cloudfoundry/multiapps/controller/persistence/model/AsyncUploadJobEntry.java

@@ -1,6 +1,7 @@
 package org.cloudfoundry.multiapps.controller.persistence.model;
 
 import java.text.MessageFormat;
+import java.time.Duration;
 import java.time.LocalDateTime;
 
 import org.cloudfoundry.multiapps.common.Nullable;
@@ -11,6 +12,10 @@
 
     String STALE_JOB_DETAILS_FORMAT = "Stale job details - id: {0}, state: {1}, updatedAt: {2}, addedAt: {3}, startedAt: {4}, bytesRead: {5}, url: {6}, space: {7}, namespace: {8}, user: {9}, instance: {10}";
 
+    String ASYNC_UPLOAD_JOB_SUMMARY_FORMAT = "id: {0}, state: {1}, fileId: {2}, mtaId: {3}, schemaVersion: {4}, instanceIndex: {5}, bytesRead: {6}, addedAt: {7}, startedAt: {8}, finishedAt: {9}, updatedAt: {10}, queueWaitTime: {11}, uploadDuration: {12}, totalTime: {13}, error: {14}";
+
+    String NOT_AVAILABLE = "N/A";
+
     enum State {
         INITIAL, RUNNING, FINISHED, ERROR
     }
@@ -61,4 +66,42 @@
         return MessageFormat.format(STALE_JOB_DETAILS_FORMAT, getId(), getState(), getUpdatedAt(), getAddedAt(), getStartedAt(),
                                     getBytesRead(), getUrl(), getSpaceGuid(), getNamespace(), getUser(), getInstanceIndex());
     }
+
+    default String buildLogSummary() {
+        return MessageFormat.format(ASYNC_UPLOAD_JOB_SUMMARY_FORMAT, getId(), getState(), getFileId(), getMtaId(), getSchemaVersion(),
+                                    getInstanceIndex(), getBytesRead(), getAddedAt(), getStartedAt(), getFinishedAt(), getUpdatedAt(),
+                                    formatDuration(getQueueWaitTime()), formatDuration(getUploadDuration()), formatDuration(getTotalTime()),
+                                    getError());
+    }
+
+    @Nullable
+    default Duration getQueueWaitTime() {
+        if (getAddedAt() == null || getStartedAt() == null) {
+            return null;
+        }
+        return Duration.between(getAddedAt(), getStartedAt());
+    }
+
+    @Nullable
+    default Duration getUploadDuration() {
+        if (getStartedAt() == null || getFinishedAt() == null) {
+            return null;
+        }
+        return Duration.between(getStartedAt(), getFinishedAt());
+    }
+
+    @Nullable
+    default Duration getTotalTime() {
+        if (getAddedAt() == null || getFinishedAt() == null) {
+            return null;
+        }
+        return Duration.between(getAddedAt(), getFinishedAt());
+    }
+
+    private static String formatDuration(Duration duration) {
+        if (duration == null) {
+            return NOT_AVAILABLE;
+        }
+        return duration.toMillis() + " ms";
+    }
 }

multiapps-controller-persistence/src/test/java/org/cloudfoundry/multiapps/controller/persistence/model/AsyncUploadJobEntryTest.java

@@ -0,0 +1,110 @@
+package org.cloudfoundry.multiapps.controller.persistence.model;
+
+import java.time.Duration;
+import java.time.LocalDateTime;
+
+import org.junit.jupiter.api.Assertions;
+import org.junit.jupiter.api.Test;
+
+class AsyncUploadJobEntryTest {
+
+    private static final String JOB_ID = "job-id";
+    private static final String FILE_ID = "file-id";
+    private static final String SPACE_GUID = "space-guid";
+    private static final String USER = "user";
+    private static final String URL = "https://user:secret@example.com/my.mtar";
+    private static final LocalDateTime ADDED_AT = LocalDateTime.of(2026, 8, 3, 10, 0, 0);
+    private static final LocalDateTime STARTED_AT = ADDED_AT.plusSeconds(30);
+    private static final LocalDateTime FINISHED_AT = STARTED_AT.plusSeconds(90);
+
+    @Test
+    void testTimingsForFinishedJob() {
+        AsyncUploadJobEntry job = baseBuilder().state(AsyncUploadJobEntry.State.FINISHED)
+                                               .addedAt(ADDED_AT)
+                                               .startedAt(STARTED_AT)
+                                               .finishedAt(FINISHED_AT)
+                                               .build();
+
+        Assertions.assertEquals(Duration.ofSeconds(30), job.getQueueWaitTime());
+        Assertions.assertEquals(Duration.ofSeconds(90), job.getUploadDuration());
+        Assertions.assertEquals(Duration.ofSeconds(120), job.getTotalTime());
+    }
+
+    @Test
+    void testTimingsAreNullWhenTimestampsMissing() {
+        AsyncUploadJobEntry runningJob = baseBuilder().state(AsyncUploadJobEntry.State.RUNNING)
+                                                      .addedAt(ADDED_AT)
+                                                      .startedAt(STARTED_AT)
+                                                      .build();
+
+        Assertions.assertEquals(Duration.ofSeconds(30), runningJob.getQueueWaitTime());
+        Assertions.assertNull(runningJob.getUploadDuration());
+        Assertions.assertNull(runningJob.getTotalTime());
+
+        AsyncUploadJobEntry initialJob = baseBuilder().state(AsyncUploadJobEntry.State.INITIAL)
+                                                      .addedAt(ADDED_AT)
+                                                      .build();
+
+        Assertions.assertNull(initialJob.getQueueWaitTime());
+        Assertions.assertNull(initialJob.getUploadDuration());
+        Assertions.assertNull(initialJob.getTotalTime());
+    }
+
+    @Test
+    void testLogSafeSummaryContainsTimingsAndFileId() {
+        AsyncUploadJobEntry job = baseBuilder().state(AsyncUploadJobEntry.State.FINISHED)
+                                               .mtaId("my-mta")
+                                               .bytesRead(2048L)
+                                               .addedAt(ADDED_AT)
+                                               .startedAt(STARTED_AT)
+                                               .finishedAt(FINISHED_AT)
+                                               .build();
+
+        String summary = job.buildLogSummary();
+
+        Assertions.assertTrue(summary.contains(JOB_ID), summary);
+        Assertions.assertTrue(summary.contains(FILE_ID), summary);
+        Assertions.assertTrue(summary.contains("my-mta"), summary);
+        Assertions.assertTrue(summary.contains("queueWaitTime: 30000 ms"), summary);
+        Assertions.assertTrue(summary.contains("uploadDuration: 90000 ms"), summary);
+        Assertions.assertTrue(summary.contains("totalTime: 120000 ms"), summary);
+    }
+
+    @Test
+    void testLogSafeSummaryHidesSensitiveData() {
+        AsyncUploadJobEntry job = baseBuilder().state(AsyncUploadJobEntry.State.RUNNING)
+                                               .addedAt(ADDED_AT)
+                                               .startedAt(STARTED_AT)
+                                               .build();
+
+        String summary = job.buildLogSummary();
+
+        Assertions.assertFalse(summary.contains(URL), summary);
+        Assertions.assertFalse(summary.contains("secret"), summary);
+        Assertions.assertFalse(summary.contains(USER), summary);
+        Assertions.assertFalse(summary.contains(SPACE_GUID), summary);
+    }
+
+    @Test
+    void testLogSafeSummaryRendersMissingTimingsAsNotAvailable() {
+        AsyncUploadJobEntry job = baseBuilder().state(AsyncUploadJobEntry.State.INITIAL)
+                                               .addedAt(ADDED_AT)
+                                               .build();
+
+        String summary = job.buildLogSummary();
+
+        Assertions.assertTrue(summary.contains("queueWaitTime: " + AsyncUploadJobEntry.NOT_AVAILABLE), summary);
+        Assertions.assertTrue(summary.contains("uploadDuration: " + AsyncUploadJobEntry.NOT_AVAILABLE), summary);
+        Assertions.assertTrue(summary.contains("totalTime: " + AsyncUploadJobEntry.NOT_AVAILABLE), summary);
+    }
+
+    private ImmutableAsyncUploadJobEntry.Builder baseBuilder() {
+        return ImmutableAsyncUploadJobEntry.builder()
+                                           .id(JOB_ID)
+                                           .fileId(FILE_ID)
+                                           .user(USER)
+                                           .url(URL)
+                                           .spaceGuid(SPACE_GUID)
+                                           .instanceIndex(0);
+    }
+}

multiapps-controller-process/src/main/java/org/cloudfoundry/multiapps/controller/process/Messages.java

@@ -820,6 +820,9 @@ public class Messages {
     public static final String IGNORING_NOT_FOUND_OPTIONAL_SERVICE = "Service {0} not found but is optional";
     public static final String IGNORING_NOT_FOUND_INACTIVE_SERVICE = "Service {0} not found but is inactive";
 
+    public static final String ASYNC_UPLOAD_JOB_FOR_OPERATION_0_IS_1 = "Async upload job for operation \"{0}\" - {1}";
+    public static final String COULD_NOT_LOG_ASYNC_UPLOAD_JOBS_FOR_OPERATION_0 = "Could not log async upload jobs for operation \"{0}\"";
+
     // Not log messages
     public static final String SERVICE_TYPE = "{0}/{1}";
     public static final String PARSE_NULL_STRING_ERROR = "Cannot parse null string";

multiapps-controller-process/src/main/java/org/cloudfoundry/multiapps/controller/process/listeners/StartProcessListener.java

@@ -19,8 +19,10 @@
 import org.cloudfoundry.multiapps.controller.api.model.ProcessType;
 import org.cloudfoundry.multiapps.controller.core.util.ApplicationConfiguration;
 import org.cloudfoundry.multiapps.controller.core.util.LoggingUtil;
+import org.cloudfoundry.multiapps.controller.persistence.model.AsyncUploadJobEntry;
 import org.cloudfoundry.multiapps.controller.persistence.model.HistoricOperationEvent;
 import org.cloudfoundry.multiapps.controller.persistence.model.ImmutableHistoricOperationEvent;
+import org.cloudfoundry.multiapps.controller.persistence.services.AsyncUploadJobService;
 import org.cloudfoundry.multiapps.controller.persistence.services.FileService;
 import org.cloudfoundry.multiapps.controller.persistence.services.FileStorageException;
 import org.cloudfoundry.multiapps.controller.persistence.services.HistoricOperationEventService;
@@ -56,14 +58,16 @@
     private final ProcessTypeToOperationMetadataMapper operationMetadataMapper;
     private final DynatracePublisher dynatracePublisher;
     private final FileService fileService;
+    private final AsyncUploadJobService asyncUploadJobService;
 
     @Inject
     public StartProcessListener(ProgressMessageService progressMessageService, StepLogger.Factory stepLoggerFactory,
                                 ProcessLoggerProvider processLoggerProvider, ProcessLoggerPersister processLoggerPersister,
                                 HistoricOperationEventService historicOperationEventService, FlowableFacade flowableFacade,
                                 ApplicationConfiguration configuration, ProcessTypeParser processTypeParser,
                                 OperationService operationService, ProcessTypeToOperationMetadataMapper operationMetadataMapper,
-                                DynatracePublisher dynatracePublisher, FileService fileService) {
+                                DynatracePublisher dynatracePublisher, FileService fileService,
+                                AsyncUploadJobService asyncUploadJobService) {
         super(progressMessageService,
               stepLoggerFactory,
               processLoggerProvider,
@@ -76,6 +80,7 @@
         this.operationMetadataMapper = operationMetadataMapper;
         this.dynatracePublisher = dynatracePublisher;
         this.fileService = fileService;
+        this.asyncUploadJobService = asyncUploadJobService;
     }
 
     @Override
@@ -92,6 +97,7 @@
         }
 
         updateOperationFiles(execution, correlationId);
+        logAsyncUploadJobs(execution, correlationId);
         getHistoricOperationEventService().add(ImmutableHistoricOperationEvent.of(correlationId, HistoricOperationEvent.EventType.STARTED));
         logProcessEnvironment();
         logProcessVariables(execution, processType, correlationId);
@@ -158,6 +164,24 @@
         }
     }
 
+    private void logAsyncUploadJobs(DelegateExecution execution, String correlationId) {
+        List<String> operationFileIds = OperationFileIdsUtil.getOperationFileIds(execution);
+        if (operationFileIds.isEmpty()) {
+            return;
+        }
+        try {
+            List<AsyncUploadJobEntry> asyncUploadJobs = asyncUploadJobService.createQuery()
+                                                                             .withFileIds(operationFileIds)
+                                                                             .list();
+            for (AsyncUploadJobEntry asyncUploadJob : asyncUploadJobs) {
+                LOGGER.info(MessageFormat.format(Messages.ASYNC_UPLOAD_JOB_FOR_OPERATION_0_IS_1, correlationId,
+                                                 asyncUploadJob.buildLogSummary()));
+            }
+        } catch (Exception e) {
+            LOGGER.warn(MessageFormat.format(Messages.COULD_NOT_LOG_ASYNC_UPLOAD_JOBS_FOR_OPERATION_0, correlationId), e);
+        }
+    }
+
     private void publishDynatraceEvent(DelegateExecution execution, ProcessType processType, String correlationId) {
         DynatraceProcessEvent startEvent = ImmutableDynatraceProcessEvent.builder()
                                                                          .processId(correlationId)

multiapps-controller-process/src/test/java/org/cloudfoundry/multiapps/controller/process/listeners/StartProcessListenerTest.java

@@ -18,6 +18,8 @@
 import org.cloudfoundry.multiapps.controller.api.model.ProcessType;
 import org.cloudfoundry.multiapps.controller.core.util.ApplicationConfiguration;
 import org.cloudfoundry.multiapps.controller.persistence.query.OperationQuery;
+import org.cloudfoundry.multiapps.controller.persistence.query.AsyncUploadJobsQuery;
+import org.cloudfoundry.multiapps.controller.persistence.services.AsyncUploadJobService;
 import org.cloudfoundry.multiapps.controller.persistence.services.FileService;
 import org.cloudfoundry.multiapps.controller.persistence.services.FileStorageException;
 import org.cloudfoundry.multiapps.controller.persistence.services.HistoricOperationEventService;
@@ -78,6 +80,10 @@
     private HistoricOperationEventService historicOperationEventService;
     @Mock
     private FileService fileService;
+    @Mock(answer = Answers.RETURNS_SELF)
+    private AsyncUploadJobService asyncUploadJobService;
+    @Mock(answer = Answers.RETURNS_SELF)
+    private AsyncUploadJobsQuery asyncUploadJobsQuery;
     @Spy
     private ProcessTypeToOperationMetadataMapper operationMetadataMapper;
     @Mock
@@ -114,7 +120,8 @@
                                             operationService,
                                             operationMetadataMapper,
                                             dynatracePublisher,
-                                            fileService);
+                                            fileService,
+                                            asyncUploadJobService);
     }
 
     @ParameterizedTest
@@ -139,6 +146,10 @@
         Mockito.doReturn(null)
                .when(operationQuery)
                .singleResult();
+        Mockito.when(asyncUploadJobService.createQuery())
+               .thenReturn(asyncUploadJobsQuery);
+        Mockito.when(asyncUploadJobsQuery.list())
+               .thenReturn(Collections.emptyList());
     }
 
     private void prepareContext() {