(ignite-3) branch main updated: IGNITE-21124 Add ability to log long message processing (#2979)

[sanpwc]

This is an automated email from the ASF dual-hosted git repository.

sanpwc pushed a commit to branch main
in repository https://gitbox.apache.org/repos/asf/ignite-3.git


The following commit(s) were added to refs/heads/main by this push:
     new 339c677008 IGNITE-21124 Add ability to log long message processing 
(#2979)
339c677008 is described below

commit 339c677008939dcb4f86e0b5aff4139c5b3fd4a2
Author: Alexander Lapin <lapin1...@gmail.com>
AuthorDate: Wed Dec 20 12:26:39 2023 +0200

    IGNITE-21124 Add ability to log long message processing (#2979)
---
 .../ignite/network/AbstractMessagingService.java   |  6 +-
 .../network/TrackableNetworkMessageHandler.java    | 65 ++++++++++++++++++++++
 2 files changed, 69 insertions(+), 2 deletions(-)

diff --git 
a/modules/network-api/src/main/java/org/apache/ignite/network/AbstractMessagingService.java
 
b/modules/network-api/src/main/java/org/apache/ignite/network/AbstractMessagingService.java
index 5d2e9abf06..e1822c8d2b 100644
--- 
a/modules/network-api/src/main/java/org/apache/ignite/network/AbstractMessagingService.java
+++ 
b/modules/network-api/src/main/java/org/apache/ignite/network/AbstractMessagingService.java
@@ -55,9 +55,11 @@ public abstract class AbstractMessagingService implements 
MessagingService {
     /** {@inheritDoc} */
     @Override
     public void addMessageHandler(Class<?> messageGroup, NetworkMessageHandler 
handler) {
+        NetworkMessageHandler trackableHandler = new 
TrackableNetworkMessageHandler(handler);
+
         handlersByGroupType.getAndUpdate(getMessageGroupType(messageGroup), 
oldHandler -> {
             if (oldHandler == null) {
-                return new Handler(messageGroup, List.of(handler));
+                return new Handler(messageGroup, List.of(trackableHandler));
             }
 
             if (oldHandler.messageGroup != messageGroup) {
@@ -71,7 +73,7 @@ public abstract class AbstractMessagingService implements 
MessagingService {
             var handlers = new 
ArrayList<NetworkMessageHandler>(oldHandler.handlers.size() + 1);
 
             handlers.addAll(oldHandler.handlers);
-            handlers.add(handler);
+            handlers.add(trackableHandler);
 
             return new Handler(messageGroup, handlers);
         });
diff --git 
a/modules/network-api/src/main/java/org/apache/ignite/network/TrackableNetworkMessageHandler.java
 
b/modules/network-api/src/main/java/org/apache/ignite/network/TrackableNetworkMessageHandler.java
new file mode 100644
index 0000000000..07dbdaae84
--- /dev/null
+++ 
b/modules/network-api/src/main/java/org/apache/ignite/network/TrackableNetworkMessageHandler.java
@@ -0,0 +1,65 @@
+/*
+ * Licensed to the Apache Software Foundation (ASF) under one or more
+ * contributor license agreements. See the NOTICE file distributed with
+ * this work for additional information regarding copyright ownership.
+ * The ASF licenses this file to You under the Apache License, Version 2.0
+ * (the "License"); you may not use this file except in compliance with
+ * the License. You may obtain a copy of the License at
+ *
+ *      http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+package org.apache.ignite.network;
+
+import static 
org.apache.ignite.internal.tostring.IgniteToStringBuilder.includeSensitive;
+
+import java.util.concurrent.TimeUnit;
+import org.apache.ignite.internal.logger.IgniteLogger;
+import org.apache.ignite.internal.logger.Loggers;
+import org.jetbrains.annotations.Nullable;
+
+/**
+ * Trackable message handler that will log long-running messages.
+ */
+public class TrackableNetworkMessageHandler implements NetworkMessageHandler {
+    private static final IgniteLogger LOG = 
Loggers.forClass(TrackableNetworkMessageHandler.class);
+
+    /**
+     * If message handling takes more time, than this constant, we will log 
warning message with some information.
+     */
+    private static final int MESSAGING_PROCESSING_LOG_THRESHOLD_MILLIS = 5;
+
+    private final NetworkMessageHandler targetHandler;
+
+    TrackableNetworkMessageHandler(NetworkMessageHandler targetHandler) {
+        this.targetHandler = targetHandler;
+    }
+
+    @Override
+    public void onReceived(NetworkMessage message, String senderConsistentId, 
@Nullable Long correlationId) {
+        long startTimeNanos = System.nanoTime();
+
+        targetHandler.onReceived(message, senderConsistentId, correlationId);
+
+        maybeLogLongProcessing(message, startTimeNanos);
+    }
+
+    private static void maybeLogLongProcessing(NetworkMessage message, long 
startTimeNanos) {
+        long durationMillis = TimeUnit.NANOSECONDS.toMillis(System.nanoTime() 
- startTimeNanos);
+
+        if (durationMillis > MESSAGING_PROCESSING_LOG_THRESHOLD_MILLIS) {
+            LOG.warn(
+                    "Message handling has been too long [duration={}ms, 
message=[{}]]",
+                    durationMillis,
+                    // Message may include sensitive data, however it seems 
useful to print full message content while testing.
+                    includeSensitive() ? message : message.getClass()
+            );
+        }
+    }
+}