make stages log in a file

[mbimbij]

Hello, i would like to make stages log in a file but i can't make it work. here is a copy paste of the same question i askes on stackoverflow :

and i am experimenting a problem with it. Here is the logback configuration :

<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <!-- encoders are assigned the type ch.qos.logback.classic.encoder.PatternLayoutEncoder 
        by default -->
    <encoder>
        <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n
        </pattern>
    </encoder>
</appender>

<timestamp key="byDay" datePattern="yyyy_MM_dd" />

<appender name="FILE" class="ch.qos.logback.core.FileAppender">
    <file>${user.home}\cognitive\logs\stages\stages-${byDay}.log</file>
    <encoder>
        <pattern>%date [%thread] %level %logger{10} [%file:%line] %msg%n
        </pattern>
    </encoder>
</appender>


<root level="INFO">
    <appender-ref ref="STDOUT" />
    <appender-ref ref="FILE" />
</root>

What happens is that when i run a main and perform logging, it works fine, but when i build a jar and the code is run through hydra, the file is created but no log is performed. the file logback.xml is inside the jar with what seems to be the appropriate content and here are the logs in hydra console :

13:32:31.349 [Thread-6] INFO  com.findwise.hydra.NodeMaster - Pipeline has been updated
13:32:32.719 [Thread-11] INFO  com.findwise.hydra.StageRunner - Starting stage group CognitiveReferentielStage. Times started so far: 0
13:32:32.722 [Thread-11] INFO  com.findwise.hydra.StageRunner - Launching with command [java, -cp, c:\java\Hydra-0.5.0\distribution\bin\hydra-cognitive\CognitiveReferentielStage\cognitive-hydra-stages-jar-with-dependencies.jar, com.findwise.hydra.stage.GroupStarter, CognitiveReferentielStage, localhost, 12001, false, 12002]
13:32:33.008 [Thread-14] INFO  com.findwise.hydra.StreamLogger - Received message from stage CognitiveReferentielStage (stdout): 13:32:32,877 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback.groovy]
13:32:33.009 [Thread-14] INFO  com.findwise.hydra.StreamLogger - Received message from stage CognitiveReferentielStage (stdout): 13:32:32,877 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.xml]
13:32:33.009 [Thread-14] INFO  com.findwise.hydra.StreamLogger - Received message from stage CognitiveReferentielStage (stdout): 13:32:32,877 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [logback.xml] at [jar:file:/C:/java/Hydra-0.5.0/distribution/bin/hydra-cognitive/CognitiveReferentielStage/cognitive-hydra-stages-jar-with-dependencies.jar!/logback.xml]
13:32:33.009 [Thread-14] INFO  com.findwise.hydra.StreamLogger - Received message from stage CognitiveReferentielStage (stdout): 13:32:32,889 |-INFO in ch.qos.logback.core.joran.spi.ConfigurationWatchList@6ed6ee82 - URL [jar:file:/C:/java/Hydra-0.5.0/distribution/bin/hydra-cognitive/CognitiveReferentielStage/cognitive-hydra-stages-jar-with-dependencies.jar!/logback.xml] is not of type file
13:32:33.020 [Thread-14] INFO  com.findwise.hydra.StreamLogger - Received message from stage CognitiveReferentielStage (stdout): 13:32:33,020 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]
13:32:33.023 [Thread-14] INFO  com.findwise.hydra.StreamLogger - Received message from stage CognitiveReferentielStage (stdout): 13:32:33,022 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [STDOUT]
13:32:33.037 [Thread-14] INFO  com.findwise.hydra.StreamLogger - Received message from stage CognitiveReferentielStage (stdout): 13:32:33,037 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
13:32:33.065 [Thread-14] INFO  com.findwise.hydra.StreamLogger - Received message from stage CognitiveReferentielStage (stdout): 13:32:33,065 |-INFO in ch.qos.logback.core.joran.action.TimestampAction - Using current interpretation time, i.e. now, as time reference.
13:32:33.065 [Thread-14] INFO  com.findwise.hydra.StreamLogger - Received message from stage CognitiveReferentielStage (stdout): 13:32:33,065 |-INFO in ch.qos.logback.core.joran.action.TimestampAction - Adding property to the context with key="byDay" and value="2014_08_08" to the context
13:32:33.066 [Thread-14] INFO  com.findwise.hydra.StreamLogger - Received message from stage CognitiveReferentielStage (stdout): 13:32:33,065 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.FileAppender]
13:32:33.067 [Thread-14] INFO  com.findwise.hydra.StreamLogger - Received message from stage CognitiveReferentielStage (stdout): 13:32:33,066 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [FILE]
13:32:33.068 [Thread-14] INFO  com.findwise.hydra.StreamLogger - Received message from stage CognitiveReferentielStage (stdout): 13:32:33,068 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
13:32:33.069 [Thread-14] INFO  com.findwise.hydra.StreamLogger - Received message from stage CognitiveReferentielStage (stdout): 13:32:33,069 |-INFO in ch.qos.logback.core.FileAppender[FILE] - File property is set to [C:\Users\Fabien\cognitive\logs\stages\stages-2014_08_08.log]
13:32:33.071 [Thread-14] INFO  com.findwise.hydra.StreamLogger - Received message from stage CognitiveReferentielStage (stdout): 13:32:33,071 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of ROOT logger to INFO
13:32:33.071 [Thread-14] INFO  com.findwise.hydra.StreamLogger - Received message from stage CognitiveReferentielStage (stdout): 13:32:33,071 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [STDOUT] to Logger[ROOT]
13:32:33.072 [Thread-14] INFO  com.findwise.hydra.StreamLogger - Received message from stage CognitiveReferentielStage (stdout): 13:32:33,071 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [FILE] to Logger[ROOT]
13:32:33.073 [Thread-14] INFO  com.findwise.hydra.StreamLogger - Received message from stage CognitiveReferentielStage (stdout): 13:32:33,071 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration.
13:32:33.074 [Thread-14] INFO  com.findwise.hydra.StreamLogger - Received message from stage CognitiveReferentielStage (stdout): 13:32:33,073 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@76757fad - Registering current configuration as safe fallback point
13:32:33.081 [Thread-1] INFO  c.q.l.classic.net.SimpleSocketServer - Connected to client at /127.0.0.1
13:32:33.081 [Thread-1] INFO  c.q.l.classic.net.SimpleSocketServer - Starting new socket node.
13:32:33.083 [Thread-1] INFO  c.q.l.classic.net.SimpleSocketServer - Waiting to accept a new client.
13:32:33.342 [I/O dispatcher 2] DEBUG com.findwise.hydra.net.RESTServer - Connection open: 127.0.0.1:12001<->127.0.0.1:51748[ACTIVE]

I am out of solutions. Thanks you

[laserval]

It looks like the correct configuration is loaded in the stage. StreamLogger is part of Hydra Core, and is capturing the console output of the stage (stdout and stderr). However, stages send logs to Hydra Core using a SocketAppender, and it appears any logging configuration is overridden on stage start: https://github.com/Findwise/Hydra/blob/master/api/src/main/java/com/findwise/hydra/Logging.java#L46

I'd suggest moving the logging configuration to an external XML file, that you load into Hydra Core on startup using -Dlogback.configurationFile=/path/to/config.xml. Also, add auto-scan to your configuration so that you can make changes at runtime:
http://logback.qos.ch/manual/configuration.html#autoScan

Hope this helps!

edit:
Ah, and when you move the configuration, you can add an appender specifically for your stage, like so:

<appender name="REF_STAGE" class="ch.qos.logback.core.FileAppender">
    <file>${user.home}\cognitive\logs\stages\stages-${byDay}.log</file>
    <encoder>
        <pattern>%date [%thread] %level %logger{10} [%file:%line] %msg%n
        </pattern>
    </encoder>
</appender>

<logger name="your.package.and.ClassName">
    <appender-ref ref="REF_STAGE"/>
</logger>

That way you can get your logs separate from the Core and other stage logs.