DPL: improve logs for new calibration scheme (#14030)

- Report correct timeout for readers.
- Improve message when dropping data which is not going to be processed by
  the CalibrationOnly mode.

Author: ktf

Framework/Core/src/DataProcessingDevice.cxx

@@ -1400,10 +1400,15 @@ void DataProcessingDevice::Run()
           O2_SIGNPOST_EVENT_EMIT(calibration, lid, "timer_setup", "Starting %d s timer for exitTransitionTimeout.",
                                  deviceContext.exitTransitionTimeout);
           uv_timer_start(deviceContext.gracePeriodTimer, on_transition_requested_expired, deviceContext.exitTransitionTimeout * 1000, 0);
-          if (mProcessingPolicies.termination == TerminationPolicy::QUIT) {
-            O2_SIGNPOST_EVENT_EMIT_INFO(device, lid, "run_loop", "New state requested. Waiting for %d seconds before quitting.", (int)deviceContext.exitTransitionTimeout);
+          bool onlyGenerated = hasOnlyGenerated(spec);
+          int timeout = onlyGenerated ? deviceContext.dataProcessingTimeout : deviceContext.exitTransitionTimeout;
+          if (mProcessingPolicies.termination == TerminationPolicy::QUIT && DefaultsHelpers::onlineDeploymentMode() == false) {
+            O2_SIGNPOST_EVENT_EMIT_INFO(device, lid, "run_loop", "New state requested. Waiting for %d seconds before quitting.", timeout);
           } else {
-            O2_SIGNPOST_EVENT_EMIT_INFO(device, lid, "run_loop", "New state requested. Waiting for %d seconds before switching to READY state.", (int)deviceContext.exitTransitionTimeout);
+            O2_SIGNPOST_EVENT_EMIT_INFO(device, lid, "run_loop",
+                                        "New state requested. Waiting for %d seconds before %{public}s",
+                                        timeout,
+                                        onlyGenerated ? "dropping remaining input and switching to READY state." : "switching to READY state.");
           }
         } else {
           state.transitionHandling = TransitionHandlingState::Expired;

Framework/Core/src/DataRelayer.cxx

@@ -8,6 +8,7 @@
 // In applying this license CERN does not waive the privileges and immunities
 // granted to it by virtue of its status as an Intergovernmental Organization
 // or submit itself to any jurisdiction.
+#include "Framework/DeviceState.h"
 #include "Framework/RootSerializationSupport.h"
 #include "Framework/DataRelayer.h"
 #include "Framework/DataProcessingStats.h"
@@ -43,6 +44,7 @@
 #include <Monitoring/Metric.h>
 #include <Monitoring/Monitoring.h>
 
+#include <fairlogger/Logger.h>
 #include <fairmq/Channel.h>
 #include <functional>
 #if __has_include(<fairmq/shmem/Message.h>)
@@ -347,9 +349,21 @@ void DataRelayer::setOldestPossibleInput(TimesliceId proposed, ChannelIndex chan
         if (element.size() == 0) {
           auto& state = mContext.get<DeviceState>();
           if (state.transitionHandling != TransitionHandlingState::NoTransition && DefaultsHelpers::onlineDeploymentMode()) {
-            LOGP(warning, "Missing {} (lifetime:{}) while dropping incomplete data in slot {} with timestamp {} < {}.", DataSpecUtils::describe(input), input.lifetime, si, timestamp.value, newOldest.timeslice.value);
+            if (state.allowedProcessing == DeviceState::CalibrationOnly) {
+              O2_SIGNPOST_ID_GENERATE(cid, calibration);
+              O2_SIGNPOST_EVENT_EMIT(calibration, cid, "expected_missing_data", "Expected missing %{public}s (lifetime:%d) while dropping non-calibration data in slot %zu with timestamp %zu < %zu.",
+                                     DataSpecUtils::describe(input).c_str(), (int)input.lifetime, si, timestamp.value, newOldest.timeslice.value);
+            } else {
+              LOGP(info, "Missing {} (lifetime:{}) while dropping incomplete data in slot {} with timestamp {} < {}.", DataSpecUtils::describe(input), input.lifetime, si, timestamp.value, newOldest.timeslice.value);
+            }
           } else {
-            LOGP(error, "Missing {} (lifetime:{}) while dropping incomplete data in slot {} with timestamp {} < {}.", DataSpecUtils::describe(input), input.lifetime, si, timestamp.value, newOldest.timeslice.value);
+            if (state.allowedProcessing == DeviceState::CalibrationOnly) {
+              O2_SIGNPOST_ID_GENERATE(cid, calibration);
+              O2_SIGNPOST_EVENT_EMIT_INFO(calibration, cid, "expected_missing_data", "Not processing in calibration mode: missing %s (lifetime:%d) while dropping incomplete data in slot %zu with timestamp %zu < %zu.",
+                                          DataSpecUtils::describe(input).c_str(), (int)input.lifetime, si, timestamp.value, newOldest.timeslice.value);
+            } else {
+              LOGP(error, "Missing {} (lifetime:{}) while dropping incomplete data in slot {} with timestamp {} < {}.", DataSpecUtils::describe(input), input.lifetime, si, timestamp.value, newOldest.timeslice.value);
+            }
           }
         }
       }