Some hazelcast INFO logs only going to STDOUT rather than SLF4J

[Daniel Lindberg]

I'm using vertx 3.1 with Hazelcast for my project, and currently struggling with some of the log records from hazelcast only ending up in STDOUT.

I have a fat-jar that I'm starting like this:

java  -Dlogback.configurationFile=logback.xml \
      -Dvertx.logger-delegate-factory-class-name=io.vertx.core.logging.SLF4JLogDelegateFactory \
      -DverticleClassName=com.test.config.ConfigVerticle \
      -Dvertx.metrics.options.enabled=true \
      -Dhazelcast.logging.type=slf4j \
      -jar target/test-bundle-1.0-SNAPSHOT-fat.jar -cluster

I have the following appenders in my logback config

<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
  <layout class="ch.qos.logback.classic.PatternLayout">
    <Pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</Pattern>
    </layout>
    </appender>
    <appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>notis.log</file>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <!-- daily rollover -->
            <fileNamePattern>notis.%d{yyyy-MM-dd}.log</fileNamePattern>
            <!-- keep 30 days' worth of history -->
            <maxHistory>14</maxHistory>
        </rollingPolicy>
        <layout class="ch.qos.logback.classic.PatternLayout">
          <Pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</Pattern>
        </layout>
    </appender>
 <logger name="com.hazelcast" level="debug" additivity="false">
        <appender-ref ref="STDOUT"/>
        <appender-ref ref="FILE" />
    </logger>

In the example below, only the last DEBUG message is being sent to SLF4J. All INFO messages above is only logged to STDOUT.

Any ideas what might be causing this?

12:55:41.034 [main] INFO  i.v.c.i.launcher.commands.RunCommand - Starting clustering...
12:55:41.041 [main] INFO  i.v.c.i.launcher.commands.RunCommand - No cluster-host specified so using address 192.168.203.106
Dec 21, 2015 12:55:41 PM com.hazelcast.instance.DefaultAddressPicker
INFO: [LOCAL] [dev] [3.5.2] Interfaces is enabled, trying to pick one address matching to one of: [127.0.0.*]
Dec 21, 2015 12:55:41 PM com.hazelcast.instance.DefaultAddressPicker
INFO: [LOCAL] [dev] [3.5.2] Prefer IPv4 stack is true.
Dec 21, 2015 12:55:41 PM com.hazelcast.instance.DefaultAddressPicker
INFO: [LOCAL] [dev] [3.5.2] Picked Address[127.0.0.1]:5701, using socket ServerSocket[addr=/0:0:0:0:0:0:0:0,localport=5701], bind any local is true
Dec 21, 2015 12:55:41 PM com.hazelcast.spi.OperationService
INFO: [127.0.0.1]:5701 [dev] [3.5.2] Backpressure is disabled
Dec 21, 2015 12:55:41 PM com.hazelcast.spi.impl.operationexecutor.classic.ClassicOperationExecutor
INFO: [127.0.0.1]:5701 [dev] [3.5.2] Starting with 2 generic operation threads and 4 partition operation threads.
Dec 21, 2015 12:55:42 PM com.hazelcast.system
INFO: [127.0.0.1]:5701 [dev] [3.5.2] Hazelcast 3.5.2 (20150826 - ba8dbba) starting at Address[127.0.0.1]:5701
Dec 21, 2015 12:55:42 PM com.hazelcast.system
INFO: [127.0.0.1]:5701 [dev] [3.5.2] Copyright (c) 2008-2015, Hazelcast, Inc. All Rights Reserved.
Dec 21, 2015 12:55:42 PM com.hazelcast.instance.Node
INFO: [127.0.0.1]:5701 [dev] [3.5.2] Creating MulticastJoiner
Dec 21, 2015 12:55:42 PM com.hazelcast.core.LifecycleService
INFO: [127.0.0.1]:5701 [dev] [3.5.2] Address[127.0.0.1]:5701 is STARTING
12:55:42.270 [vert.x-worker-thread-0] DEBUG com.hazelcast.nio.UTFEncoderDecoder - Old String constructor doesn't seem available
java.lang.NoSuchMethodException: java.lang.String.<init>(int, int, [C)
 at java.lang.Class.getConstructor0(Class.java:3082) ~[na:1.8.0_60]
 at java.lang.Class.getDeclaredConstructor(Class.java:2178) ~[na:1.8.0_60]

[Michael Miller]

Having the same problem here.

[Daniel Lindberg]

Eventually found out what my issue was. 

Check your cluster.xml. I had something along these lines in mine,

<properties>
   <property name="hazelcast.logging.type">jdk</property>
</properties>

which apparently was overriding whatever I passed on the command line

Den måndag 14 mars 2016 kl. 19:45:44 UTC+1 skrev Michael Miller:

Having the same problem here.

[Clement Escoffier]

Hi,

This property is also set in the default cluster configuration. 

Could you open an issue on vertx-hazelcast, so we indicate in the documentation that this value need to be changed in a custom cluster.xml if you use another log framework.

Thanks,

Clement

--
You received this message because you are subscribed to the Google Groups "vert.x" group.
To unsubscribe from this group and stop receiving emails from it, send an email to vertx+un...@googlegroups.com.
Visit this group at https://groups.google.com/group/vertx.
To view this discussion on the web, visit https://groups.google.com/d/msgid/vertx/e06ec7e2-ce5b-409b-a58c-c97761ea9894%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[Daniel Lindberg]

Added it here

https://github.com/vert-x3/vertx-hazelcast/issues/27