DM-3212 2024 Enhanced Debug Logging for Loriot (#454)

DM-3212 Extra Debug logs with Request ID during uplink payload Debugging for LPWAN (#449)

* Extra Debug logs with Request ID during uplink payload Debugging for LPWAN

* Use MDC approach for logging

(cherry picked from commit 67b470e)

lpwan-backend/src/main/java/com/cumulocity/lpwan/payload/service/PayloadDecoderService.java

@@ -25,11 +25,14 @@
 import com.cumulocity.rest.representation.inventory.ManagedObjectRepresentation;
 import lombok.extern.slf4j.Slf4j;
 import org.apache.commons.lang3.StringUtils;
+import org.slf4j.MDC;
 import org.springframework.beans.factory.annotation.Autowired;
 
 import java.util.List;
 import java.util.Optional;
 
+import static java.util.Arrays.asList;
+
 @Slf4j
 public class PayloadDecoderService<T extends UplinkMessage> {
     @Autowired
@@ -83,6 +86,7 @@ public static Integer messageIdFromPayload(UplinkMessage uplink, MessageIdConfig
      * @param deviceType    the device type
      */
     public void decodeAndMap(T uplinkMessage, ManagedObjectRepresentation source, DeviceType deviceType) {
+        String requestId = MDC.get("requestId");
         final String tenantId = contextService.getContext().getTenant();
         Optional<MicroserviceCredentials> serviceUser = subscriptionsService.getCredentials(tenantId);
         contextService.runWithinContext(serviceUser.get(), () -> {
@@ -97,38 +101,45 @@ public void decodeAndMap(T uplinkMessage, ManagedObjectRepresentation source, De
                     MessageTypeMapping messageTypeMappings = deviceType.getMessageTypes().getMappingIndexesByMessageType(Integer.toString(messageTypeId));
 
                     if (messageTypeMappings == null) {
-                        log.warn("Message type id {} not found for device type {}", messageTypeId, deviceType);
+                        log.warn("Request Id {}, Message type id {} not found for device type {}", requestId, messageTypeId, deviceType);
                         return;
                     }
 
                     MappingCollections mappingCollections = new MappingCollections();
+                    log.debug("Request Id {}, Decoding payload for device type {}", requestId, deviceType.getName());
                     for (Integer registerIndex : messageTypeMappings.getRegisterIndexes()) {
 
                         try {
                             UplinkConfiguration uplinkConfiguration = uplinkConfigurations.get(registerIndex);
                             DecodedObject decodedObject = generateDecodedData(uplinkMessage, uplinkConfiguration);
                             payloadMappingService.addMappingsToCollection(mappingCollections, decodedObject, uplinkConfiguration);
                         } catch (PayloadDecodingFailedException e) {
-                            log.error("Error decoding payload for device type {}: {} Skipping decoding payload part", deviceType, e.getMessage());
+                            log.error("Request Id {}, Error decoding payload for device type {}: {} Skipping decoding payload part", requestId, deviceType, e.getMessage());
                         }
                     }
+                    log.debug("Request Id {}, Executing mappings for device type {}", requestId, deviceType.getName());
                     payloadMappingService.executeMappings(mappingCollections, source, uplinkMessage.getDateTime());
+                    log.debug("Request Id {}, Mappings executed for device type {}", requestId, deviceType.getName());
                 } catch (Exception e) {
-                    log.error(e.getMessage());
+                    log.error("Request Id {}, exception: {}", requestId, e.getMessage());
                 }
             } else {
                 DecoderResult decoderResult;
                 try {
+                    log.debug("Request Id {}, Decoding using custom codec for device type {}", requestId, deviceType.getName());
                     decoderResult = lpwanCodecService.decode(deviceType, source, uplinkMessage);
+                    log.debug("Request Id {}, Decoding using custom codec for device type {} completed", requestId, deviceType.getName());
                 } catch (LpwanCodecServiceException e) {
                     decoderResult = DecoderResult.empty();
                     decoderResult.setAsFailed(String.format("Error decoding payload for device EUI '%s'. Skipping the decoding of the payload part. \nCause: %s", uplinkMessage.getExternalId(), e.getMessage()));
                 }
 
                 try {
+                    log.debug("Request Id {}, Handling the decoder response for the device with EUI '{}'", requestId, uplinkMessage.getExternalId());
                     payloadMappingService.handleCodecServiceResponse(decoderResult, source, uplinkMessage.getExternalId());
+                    log.debug("Request Id {}, Handling the decoder response for the device with EUI '{}' completed", requestId, uplinkMessage.getExternalId());
                 } catch (PayloadDecodingFailedException e) {
-                    log.error("Error handling the decoder response for the device with EUI '{}'.", uplinkMessage.getExternalId(), e);
+                    log.error("Request Id {}, Error handling the decoder response for the device with EUI '{}'.", requestId, uplinkMessage.getExternalId(), e);
                 }
             }
         });