Merge pull request #297 from scalecube/update/logging

Updated logging
scalecube · Jan 23, 2020 · cfb058d · cfb058d
2 parents a7fba99 + 3f91dfd
commit cfb058d
Show file tree

Hide file tree

Showing 14 changed files with 71 additions and 93 deletions.
diff --git a/cluster/src/main/java/io/scalecube/cluster/ClusterImpl.java b/cluster/src/main/java/io/scalecube/cluster/ClusterImpl.java
@@ -479,21 +479,21 @@ public void shutdown() {
   private Mono<Void> doShutdown() {
     return Mono.defer(
         () -> {
-          LOGGER.debug("[{}] Cluster member is shutting down", localMember);
+          LOGGER.info("[{}] Cluster member is shutting down", localMember);
           return Flux.concatDelayError(leaveCluster(), dispose(), transport.stop())
               .then()
               .doFinally(s -> scheduler.dispose())
               .doOnSuccess(
-                  avoid -> LOGGER.debug("[{}] Cluster member has been shutdown", localMember));
+                  avoid -> LOGGER.info("[{}] Cluster member has been shutdown", localMember));
         });
   }
 
   private Mono<Void> leaveCluster() {
     return membership
         .leaveCluster()
         .subscribeOn(scheduler)
-        .doOnSubscribe(s -> LOGGER.debug("[{}] Cluster member is leaving a cluster", localMember))
-        .doOnSuccess(s -> LOGGER.debug("[{}] Cluster member has left a cluster", localMember))
+        .doOnSubscribe(s -> LOGGER.info("[{}] Cluster member is leaving a cluster", localMember))
+        .doOnSuccess(s -> LOGGER.info("[{}] Cluster member has left a cluster", localMember))
         .doOnError(
             ex ->
                 LOGGER.warn(

diff --git a/cluster/src/main/java/io/scalecube/cluster/fdetector/FailureDetectorImpl.java b/cluster/src/main/java/io/scalecube/cluster/fdetector/FailureDetectorImpl.java
@@ -151,7 +151,7 @@ private void doPing() {
               publishPingResult(period, pingMember, computeMemberStatus(message, period));
             },
             ex -> {
-              LOGGER.debug(
+              LOGGER.warn(
                   "[{}][{}] Failed to get PingAck from {} within {} ms",
                   localMember,
                   period,
@@ -198,7 +198,7 @@ private void doPingReq(
                       publishPingResult(period, pingMember, computeMemberStatus(message, period));
                     },
                     throwable -> {
-                      LOGGER.debug(
+                      LOGGER.warn(
                           "[{}][{}] Timeout getting transit PingAck from {} to {} within {} ms",
                           localMember,
                           period,
@@ -250,7 +250,7 @@ private void onPing(Message message) {
         .subscribe(
             null,
             ex ->
-                LOGGER.debug(
+                LOGGER.warn(
                     "[{}][{}] Failed to send PingAck to {}, cause: {}",
                     localMember,
                     period,
@@ -276,7 +276,7 @@ private void onPingReq(Message message) {
         .subscribe(
             null,
             ex ->
-                LOGGER.debug(
+                LOGGER.warn(
                     "[{}][{}] Failed to send transit Ping to {}, cause: {}",
                     localMember,
                     period,
@@ -306,7 +306,7 @@ private void onTransitPingAck(Message message) {
         .subscribe(
             null,
             ex ->
-                LOGGER.debug(
+                LOGGER.warn(
                     "[{}][{}] Failed to resend transit PingAck to {}, cause: {}",
                     localMember,
                     period,

diff --git a/cluster/src/main/java/io/scalecube/cluster/gossip/GossipProtocolImpl.java b/cluster/src/main/java/io/scalecube/cluster/gossip/GossipProtocolImpl.java
@@ -299,7 +299,7 @@ private void spreadGossipsTo(long period, Member member) {
                     .subscribe(
                         null,
                         ex ->
-                            LOGGER.debug(
+                            LOGGER.warn(
                                 "[{}][{}] Failed to send GossipReq({}) to {}, cause: {}",
                                 localMember,
                                 period,

diff --git a/cluster/src/main/java/io/scalecube/cluster/membership/MembershipProtocolImpl.java b/cluster/src/main/java/io/scalecube/cluster/membership/MembershipProtocolImpl.java
@@ -261,7 +261,7 @@ private void start0(MonoSink<Object> sink) {
       return;
     }
     // If seed addresses are specified in config - send initial sync to those nodes
-    LOGGER.debug("[{}] Making initial Sync to all seed members: {}", localMember, seedMembers);
+    LOGGER.info("[{}] Making initial Sync to all seed members: {}", localMember, seedMembers);
 
     //noinspection unchecked
     Mono<Message>[] syncs =
@@ -289,7 +289,7 @@ private void start0(MonoSink<Object> sink) {
         .subscribe(
             null,
             ex ->
-                LOGGER.debug(
+                LOGGER.warn(
                     "[{}] Exception on initial SyncAck, cause: {}", localMember, ex.toString()));
   }
 
@@ -352,7 +352,7 @@ private void doSync() {
         .subscribe(
             null,
             ex ->
-                LOGGER.debug(
+                LOGGER.warn(
                     "[{}][doSync] Failed to send Sync to {}, cause: {}",
                     localMember,
                     address,
@@ -403,7 +403,7 @@ private Mono<Void> onSync(Message syncMsg) {
                         .subscribe(
                             null,
                             ex ->
-                                LOGGER.debug(
+                                LOGGER.warn(
                                     "[{}] Failed to send SyncAck to {}, cause: {}",
                                     localMember,
                                     sender,
@@ -433,7 +433,7 @@ private void onFailureDetectorEvent(FailureDetectorEvent fdEvent) {
           .subscribe(
               null,
               ex ->
-                  LOGGER.debug(
+                  LOGGER.warn(
                       "[{}][onFailureDetectorEvent] Failed to send Sync to {}, cause: {}",
                       localMember,
                       address,
@@ -581,7 +581,7 @@ private Mono<Void> updateMembership(MembershipRecord r1, MembershipUpdateReason
                   .fetchMetadata(r1.member())
                   .doOnError(
                       ex ->
-                          LOGGER.debug(
+                          LOGGER.warn(
                               "[{}][updateMembership][{}] Skipping to add/update member: {}, "
                                   + "due to failed fetchMetadata call (cause: {})",
                               localMember,
@@ -676,7 +676,7 @@ private Mono<Void> onLeavingDetected(MembershipRecord r0, MembershipRecord r1) {
   }
 
   private void publishEvent(MembershipEvent event) {
-    LOGGER.debug("[{}][publishEvent] {}", localMember, event);
+    LOGGER.info("[{}][publishEvent] {}", localMember, event);
     sink.next(event);
   }
 
@@ -699,9 +699,9 @@ private Mono<Void> onDeadMemberDetected(MembershipRecord r1) {
 
           // Log that member leaved gracefully or without notification
           if (r0.isLeaving()) {
-            LOGGER.debug("[{}] Member leaved gracefully: {}", localMember, member);
+            LOGGER.info("[{}] Member leaved gracefully: {}", localMember, member);
           } else {
-            LOGGER.warn("[{}] Member leaved without notification: {}", localMember, member);
+            LOGGER.info("[{}] Member leaved without notification: {}", localMember, member);
           }
 
           final long timestamp = System.currentTimeMillis();
@@ -756,7 +756,7 @@ private void scheduleSuspicionTimeoutTask(MembershipRecord r) {
         r.member().id(),
         id -> {
           LOGGER.debug(
-              "[{}] Scheduled SuspicionTimeoutTask for {}, suspicionTimeout {}",
+              "[{}] Scheduled SuspicionTimeoutTask for {}, suspicionTimeout: {}",
               localMember,
               id,
               suspicionTimeout);
@@ -794,7 +794,7 @@ private Mono<Void> spreadMembershipGossip(MembershipRecord r) {
               .spread(msg)
               .doOnError(
                   ex ->
-                      LOGGER.debug(
+                      LOGGER.warn(
                           "[{}] Failed to send membership with gossip, cause: {}",
                           localMember,
                           ex.toString()))
@@ -864,10 +864,7 @@ private List<Member> getSuspectedMembers() {
   }
 
   private List<Member> getRemovedMembers() {
-    return removedMembersHistory //
-        .stream()
-        .map(MembershipEvent::member)
-        .collect(Collectors.toList());
+    return removedMembersHistory.stream().map(MembershipEvent::member).collect(Collectors.toList());
   }
 
   private List<Member> findRecordsByCondition(Predicate<MembershipRecord> condition) {

diff --git a/cluster/src/test/java/io/scalecube/cluster/ClusterTest.java b/cluster/src/test/java/io/scalecube/cluster/ClusterTest.java
@@ -171,10 +171,7 @@ public void testJoinDynamicPort() {
     } finally {
       // Shutdown all nodes
       shutdown(
-          Stream.concat(
-                  Stream.of(seedNode), //
-                  otherNodes.stream())
-              .collect(Collectors.toList()));
+          Stream.concat(Stream.of(seedNode), otherNodes.stream()).collect(Collectors.toList()));
     }
   }
 
@@ -243,9 +240,7 @@ public void onMembershipEvent(MembershipEvent event) {
     } finally {
       // Shutdown all nodes
       shutdown(
-          Stream.concat(
-                  Stream.of(seedNode, metadataNode), //
-                  otherNodes.stream())
+          Stream.concat(Stream.of(seedNode, metadataNode), otherNodes.stream())
               .collect(Collectors.toList()));
     }
   }
@@ -321,9 +316,7 @@ public void onMembershipEvent(MembershipEvent event) {
     } finally {
       // Shutdown all nodes
       shutdown(
-          Stream.concat(
-                  Stream.of(seedNode, metadataNode), //
-                  otherNodes.stream())
+          Stream.concat(Stream.of(seedNode, metadataNode), otherNodes.stream())
               .collect(Collectors.toList()));
     }
   }
@@ -400,9 +393,7 @@ public void onMembershipEvent(MembershipEvent event) {
     } finally {
       // Shutdown all nodes
       shutdown(
-          Stream.concat(
-                  Stream.of(seedNode, metadataNode), //
-                  otherNodes.stream())
+          Stream.concat(Stream.of(seedNode, metadataNode), otherNodes.stream())
               .collect(Collectors.toList()));
     }
   }

diff --git a/cluster/src/test/java/io/scalecube/cluster/fdetector/FailureDetectorTest.java b/cluster/src/test/java/io/scalecube/cluster/fdetector/FailureDetectorTest.java
@@ -26,7 +26,6 @@
 import org.junit.jupiter.api.AfterEach;
 import org.junit.jupiter.api.BeforeEach;
 import org.junit.jupiter.api.Test;
-import org.junit.jupiter.api.TestInfo;
 import reactor.core.publisher.Flux;
 import reactor.core.scheduler.Scheduler;
 import reactor.core.scheduler.Schedulers;
@@ -36,8 +35,8 @@ public class FailureDetectorTest extends BaseTest {
   private Scheduler scheduler;
 
   @BeforeEach
-  void setUp(TestInfo testInfo) {
-    scheduler = Schedulers.newSingle(testInfo.getDisplayName().replaceAll(" ", "_"), true);
+  void setUp() {
+    scheduler = Schedulers.newSingle("scheduler", true);
   }
 
   @AfterEach

diff --git a/cluster/src/test/java/io/scalecube/cluster/gossip/GossipProtocolTest.java b/cluster/src/test/java/io/scalecube/cluster/gossip/GossipProtocolTest.java
@@ -30,7 +30,6 @@
 import java.util.stream.Stream;
 import org.junit.jupiter.api.AfterEach;
 import org.junit.jupiter.api.BeforeEach;
-import org.junit.jupiter.api.TestInfo;
 import org.junit.jupiter.params.ParameterizedTest;
 import org.junit.jupiter.params.provider.Arguments;
 import org.junit.jupiter.params.provider.MethodSource;
@@ -92,8 +91,8 @@ static Stream<Arguments> experiment() {
   private Scheduler scheduler;
 
   @BeforeEach
-  void setUp(TestInfo testInfo) {
-    scheduler = Schedulers.newSingle(testInfo.getDisplayName().replaceAll(" ", "_"), true);
+  void setUp() {
+    scheduler = Schedulers.newSingle("scheduler", true);
   }
 
   @AfterEach

diff --git a/cluster/src/test/java/io/scalecube/cluster/membership/MembershipProtocolTest.java b/cluster/src/test/java/io/scalecube/cluster/membership/MembershipProtocolTest.java
@@ -30,7 +30,6 @@
 import org.junit.jupiter.api.AfterEach;
 import org.junit.jupiter.api.BeforeEach;
 import org.junit.jupiter.api.Test;
-import org.junit.jupiter.api.TestInfo;
 import reactor.core.Exceptions;
 import reactor.core.publisher.DirectProcessor;
 import reactor.core.publisher.Flux;
@@ -51,8 +50,8 @@ public class MembershipProtocolTest extends BaseTest {
   private Scheduler scheduler;
 
   @BeforeEach
-  void setUp(TestInfo testInfo) {
-    scheduler = Schedulers.newSingle(testInfo.getDisplayName().replaceAll(" ", "_"), true);
+  void setUp() {
+    scheduler = Schedulers.newSingle("scheduler", true);
     stopables = new ArrayList<>();
   }
 

diff --git a/cluster/src/test/resources/log4j2-test.xml b/cluster/src/test/resources/log4j2-test.xml
@@ -4,23 +4,21 @@
   <Appenders>
     <Console name="console" target="SYSTEM_OUT">
       <PatternLayout>
-        <pattern>%level{length=1} %date{MMdd-HHmm:ss,SSS} %logger{1.} %message [%thread]%n</pattern>
+        <pattern>%level{length=1} %date{HHmm:ss,SSS} %logger{1.} %message [%thread]%n</pattern>
       </PatternLayout>
     </Console>
   </Appenders>
 
   <Loggers>
-    <Logger name="io.netty" level="info"/>
-    <Logger name="reactor.netty" level="info"/>
-    <Logger name="io.scalecube.cluster.transport" level="info"/>
-    <Logger name="io.scalecube.cluster.fdetector" level="info"/>
-    <Logger name="io.scalecube.cluster.gossip" level="info"/>
-    <Logger name="io.scalecube.cluster.membership" level="info"/>
-    <Logger name="io.scalecube.cluster.metadata" level="info"/>
-    <Logger name="io.scalecube.cluster" level="info"/>
-    <Logger name="io.scalecube.services" level="info"/>
+    <Logger name="io.netty" level="${env:nettyLogLevel:-error}"/>
+    <Logger name="reactor.netty" level="${env:reactorNettyLogLevel:-error}"/>
+    <Logger name="io.scalecube.cluster.transport" level="${env:clusterTransport:-error}"/>
+    <Logger name="io.scalecube.cluster.fdetector" level="${env:clusterFdetector:-error}"/>
+    <Logger name="io.scalecube.cluster.gossip" level="${env:clusterGossip:-error}"/>
+    <Logger name="io.scalecube.cluster.membership" level="${env:clusterMembership:-error}"/>
+    <Logger name="io.scalecube.cluster.metadata" level="${env:clusterMetadata:-error}"/>
 
-    <Root level="info">
+    <Root level="${env:logLevel:-error}">
       <AppenderRef ref="console"/>
     </Root>
   </Loggers>

diff --git a/transport-parent/transport-api/src/main/java/io/scalecube/cluster/transport/api/Message.java b/transport-parent/transport-api/src/main/java/io/scalecube/cluster/transport/api/Message.java
@@ -197,8 +197,8 @@ public Address sender() {
   @Override
   public String toString() {
     return new StringJoiner(", ", Message.class.getSimpleName() + "[", "]")
-        .add("headers=" + headers)
-        .add("data=" + data)
+        .add("headers(" + headers.size() + ")")
+        .add("data=" + (data != null ? data.getClass().getName() : null))
         .toString();
   }
 

diff --git a/...port-parent/transport-netty/src/main/java/io/scalecube/transport/netty/TransportImpl.java b/...port-parent/transport-netty/src/main/java/io/scalecube/transport/netty/TransportImpl.java
@@ -188,7 +188,7 @@ public Mono<Transport> bind0() {
                     config.port(),
                     ex.toString()))
         .map(server -> new TransportImpl(server, this))
-        .doOnSuccess(t -> LOGGER.debug("[{}] Bound cluster transport", address))
+        .doOnSuccess(t -> LOGGER.info("[{}] Bound cluster transport", t.address()))
         .cast(Transport.class);
   }
 
@@ -214,13 +214,13 @@ public final Mono<Void> stop() {
   private Mono<Void> doStop() {
     return Mono.defer(
         () -> {
-          LOGGER.debug("[{}] Transport is shutting down", address);
+          LOGGER.info("[{}] Transport is shutting down", address);
           // Complete incoming messages observable
           messageSink.complete();
           return Flux.concatDelayError(closeServer(), shutdownLoopResources())
               .then()
               .doFinally(s -> connections.clear())
-              .doOnSuccess(avoid -> LOGGER.debug("[{}] Transport has been shut down", address));
+              .doOnSuccess(avoid -> LOGGER.info("[{}] Transport has been shut down", address));
         });
   }
 
@@ -233,6 +233,7 @@ public final Flux<Message> listen() {
   public Mono<Void> send(Address address, Message message) {
     return connections
         .computeIfAbsent(address, this::connect0)
+        .doOnSubscribe(s -> LOGGER.debug("[{}] Send {} to {}", this.address, message, address))
         .map(Connection::outbound)
         .flatMap(out -> out.send(Mono.just(message).map(this::toByteBuf), bb -> true).then())
         .then();
@@ -267,11 +268,7 @@ public Mono<Message> requestResponse(Address address, final Message request) {
 
   @SuppressWarnings("unused")
   private Mono<Void> onMessage(NettyInbound in, NettyOutbound out) {
-    return in.receive() //
-        .retain()
-        .map(this::toMessage)
-        .doOnNext(messageSink::next)
-        .then();
+    return in.receive().retain().map(this::toMessage).doOnNext(messageSink::next).then();
   }
 
   private Message toMessage(ByteBuf byteBuf) {
@@ -300,15 +297,15 @@ private Mono<? extends Connection> connect0(Address address) {
     return newTcpClient(address)
         .doOnDisconnected(
             c -> {
-              LOGGER.debug("[{}] Disconnected from: {}, {}", this.address, address, c.channel());
+              LOGGER.debug("[{}] Disconnected from {}, {}", this.address, address, c.channel());
               connections.remove(address);
             })
         .doOnConnected(
             c -> LOGGER.debug("[{}] Connected to {}, {}", this.address, address, c.channel()))
         .connect()
         .doOnError(
             th -> {
-              LOGGER.debug(
+              LOGGER.warn(
                   "[{}][connect0][{}] Exception occurred: {}",
                   this.address,
                   address,