log execution time warning.

sonus21 · Dec 3, 2020 · b66d2cf · b66d2cf
1 parent 991d80d
commit b66d2cf
Showing 1 changed file with 22 additions and 3 deletions.
diff --git a/rqueue-core/src/main/java/com/github/sonus21/rqueue/listener/RqueueExecutor.java b/rqueue-core/src/main/java/com/github/sonus21/rqueue/listener/RqueueExecutor.java
@@ -104,10 +104,12 @@ private void updateCounter(boolean fail) {
     }
   }
 
+  private long maxExecutionTime() {
+    return queueDetail.getVisibilityTimeout() - DELTA_BETWEEN_RE_ENQUEUE_TIME;
+  }
+
   private long getMaxProcessingTime() {
-    return System.currentTimeMillis()
-        + queueDetail.getVisibilityTimeout()
-        - DELTA_BETWEEN_RE_ENQUEUE_TIME;
+    return System.currentTimeMillis() + maxExecutionTime();
   }
 
   private boolean isMessageDeleted() {
@@ -167,6 +169,22 @@ private void updateToProcessing() {
         messageMetadata, Duration.ofMinutes(rqueueConfig.getMessageDurabilityInMinute()));
   }
 
+  private void logExecutionTimeWarning(
+      long maxProcessingTime, long startTime, ExecutionStatus status) {
+    if (System.currentTimeMillis() > maxProcessingTime) {
+      long maxAllowedTime = maxExecutionTime();
+      long executionTime = System.currentTimeMillis() - startTime;
+      log(
+          Level.WARN,
+          "Message listener is taking longer time [Queue: {}, TaskStatus: {}] MaxAllowedTime: {}, ExecutionTime: {}",
+          null,
+          queueDetail.getQueueName(),
+          status,
+          maxAllowedTime,
+          executionTime);
+    }
+  }
+
   @Override
   void start() {
     int failureCount = rqueueMessage.getFailureCount();
@@ -206,6 +224,7 @@ void start() {
           (status == null ? ExecutionStatus.FAILED : status),
           failureCount,
           startTime);
+      logExecutionTimeWarning(maxProcessingTime, startTime, status);
     } finally {
       semaphore.release();
     }