search

gschueler / rundeck-log4j-streaming-log-plugin

0 stars 0 forks source link

Can't seem to get logger to take effect #1

Open daneuriona opened 10 years ago

daneuriona commented 10 years ago

Hi gschueler thanks for all the really great Rundeck plugins they've been a huge help. I'm trying to get the streaming logger to work but seem to be missing something,

I've added this line in rundeck-config.properties:

rundeck.execution.logs.streamingWriterPlugins=log4jStreamingLogWriterPlugin

I've added this line in framework.properties:

framework.plugin.StreamingLogWriter.log4jStreamingLogWriterPlugin.loggername=org.rundeck.log.event.stream

I've added these lines in log4j.properties:

log4j.logger.org.rundeck.log.event.stream=info,executionevents,stdout
log4j.additivity.org.rundeck.log.event.stream=false

log4j.appender.executionevents=org.apache.log4j.DailyRollingFileAppender
log4j.appender.executionevents.file=/home/vagrant/rundeck/var/logs/rundeck.executionevents.log
log4j.appender.executionevents.append=true
log4j.appender.executionevents.layout=org.apache.log4j.PatternLayout
log4j.appender.executionevents.layout.ConversionPattern=%d{ISO8601} project: %X{project} execution: %X{execid} (%X{event}, %X{nodename}) %X{group}/%X{name} [%X{id}] - %m%n

And I put the file log4jStreamingLogWriterPlugin.groovy, in libext.

After restarting and running jobs, still can't get the file at /home/vagrant/rundeck/var/logs to show up.

What am I missing here?

daneuriona commented 10 years ago

PS Running Rundeck 2.1.2 on Ubuntu 1404 with the standalone jar.

gschueler commented 10 years ago

what is the location of the log4j.properties file? If you are using the standalone jar, make sure it is not overwriting the log4j.properties file when it starts up (use the --skipinstall option)

daneuriona commented 10 years ago

When I run jobs at debug level I get this in the rundeck.log:

2014-06-25 10:20:50,620 ERROR DisablingLogWriter - Failed addEvent for StreamingLogWriter(log4jStreamingLogWriterPlugin), disabling. null
gschueler commented 10 years ago

ok, try changing the log4j log level to DEBUG for "rundeck.services.logging" and that should reveal a stacktrace about why it is disabling the plugin

daneuriona commented 10 years ago

The only place I'm seeing rundeck.services.logging is in /server/exp/webapp/WEB-INF/grails.xml. Sorry is there another place I should be setting it?

Maybe something like rundeck.services.logging.setLevel(Level.DEBUG) in the log4j.properties?

gschueler commented 10 years ago

sorry, add a line like this to the server/exp/webapp/WEB-INF/classes/log4j.properties file and restart:

log4j.logger.rundeck.services.logging=DEBUG,stdout

daneuriona commented 10 years ago

Cool added the line, it is the only line for rundeck.services inside that file so I'm guessing by default the rundeck.services logger is disabled. I know in other applications I've used log4j changes get picked up without a restart, is that the case here?

Only difference I'm seeing in stdout is:

2014-06-25 11:05:07,729 WARN  ExecutionJob - ExecutionJob: Execution not found with ID [24], will retry for up to 60 seconds...
2014-06-25 11:05:09,907 ERROR DisablingLogWriter - Failed addEvent for StreamingLogWriter(log4jStreamingLogWriterPlugin), disabling. null
gschueler commented 10 years ago

you probably have to restart

daneuriona commented 10 years ago

Here's the DEBUG info:

2014-06-25 11:17:32,439 ERROR DisablingLogWriter - Failed addEvent for StreamingLogWriter(log4jStreamingLogWriterPlugin), disabling. null
2014-06-25 11:17:32,439 ERROR DisablingLogWriter - Failed addEvent for StreamingLogWriter(log4jStreamingLogWriterPlugin), disabling. null
2014-06-25 11:17:32,452 DEBUG DisablingLogWriter - Failed addEvent for StreamingLogWriter(log4jStreamingLogWriterPlugin), disabling. null
java.lang.NullPointerException
    at org.codehaus.groovy.runtime.DefaultGroovyMethods.putAll(DefaultGroovyMethods.java:6184)
    at org.codehaus.groovy.runtime.DefaultGroovyMethods.plus(DefaultGroovyMethods.java:6206)
    at org.codehaus.groovy.runtime.dgm$390.invoke(Unknown Source)
    at org.codehaus.groovy.runtime.callsite.PojoMetaMethodSite$PojoMetaMethodSiteNoUnwrapNoCoerce.invoke(PojoMetaMethodSite.java:271)
    at org.codehaus.groovy.runtime.callsite.PojoMetaMethodSite.call(PojoMetaMethodSite.java:53)
    at org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCall(CallSiteArray.java:45)
    at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:108)
    at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:116)
    at log4jStreamingLogWriterPlugin$_run_closure1_closure7.doCall(log4jStreamingLogWriterPlugin:104)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.codehaus.groovy.runtime.callsite.PogoMetaMethodSite$PogoCachedMethodSiteNoUnwrapNoCoerce.invoke(PogoMetaMethodSite.java:272)
    at org.codehaus.groovy.runtime.callsite.PogoMetaMethodSite.call(PogoMetaMethodSite.java:64)
    at org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCall(CallSiteArray.java:45)
    at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:108)
    at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:120)
    at com.dtolabs.rundeck.server.plugins.builder.ScriptStreamingLogWriterPlugin.addEvent(ScriptStreamingLogWriterPlugin.groovy:74)
    at com.dtolabs.rundeck.core.logging.StreamingLogWriter$addEvent.call(Unknown Source)
    at org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCall(CallSiteArray.java:45)
    at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:108)
    at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:116)
    at rundeck.services.logging.DisablingLogWriter.addEvent(DisablingLogWriter.groovy:42)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:90)
    at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:233)
    at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1082)
    at groovy.lang.ExpandoMetaClass.invokeMethod(ExpandoMetaClass.java:1106)
    at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:906)
    at org.codehaus.groovy.runtime.InvokerHelper.invokePogoMethod(InvokerHelper.java:848)
    at org.codehaus.groovy.runtime.InvokerHelper.invokeMethod(InvokerHelper.java:831)
    at org.codehaus.groovy.runtime.ScriptBytecodeAdapter.invokeMethodN(ScriptBytecodeAdapter.java:164)
    at org.codehaus.groovy.runtime.ScriptBytecodeAdapter.invokeMethodNSafe(ScriptBytecodeAdapter.java:172)
    at org.codehaus.groovy.runtime.ScriptBytecodeAdapter.invokeMethodNSpreadSafe(ScriptBytecodeAdapter.java:179)
    at rundeck.services.logging.MultiLogWriter.addEvent(MultiLogWriter.groovy:29)
    at com.dtolabs.rundeck.core.logging.StreamingLogWriter$addEvent.call(Unknown Source)
    at org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCall(CallSiteArray.java:45)
    at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:108)
    at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:116)
    at rundeck.services.logging.LoglevelThresholdLogWriter.addEvent(LoglevelThresholdLogWriter.groovy:22)
    at com.dtolabs.rundeck.core.logging.FilterStreamingLogWriter.addEvent(FilterStreamingLogWriter.java:21)
    at com.dtolabs.rundeck.core.logging.ContextLogWriter.verbose(ContextLogWriter.java:51)
    at com.dtolabs.rundeck.core.execution.workflow.ContextualExecutionListener.log(ContextualExecutionListener.java:96)
    at com.dtolabs.rundeck.core.execution.workflow.WorkflowExecutionListenerImpl.log(WorkflowExecutionListenerImpl.java:42)
    at com.dtolabs.rundeck.core.execution.workflow.ContextualExecutionListener.log(ContextualExecutionListener.java:60)
    at com.dtolabs.rundeck.core.execution.workflow.WorkflowExecutionListenerImpl.beginWorkflowExecution(WorkflowExecutionListenerImpl.java:159)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:90)
    at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:233)
    at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1082)
    at groovy.lang.ExpandoMetaClass.invokeMethod(ExpandoMetaClass.java:1106)
    at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:906)
    at org.codehaus.groovy.runtime.InvokerHelper.invokePojoMethod(InvokerHelper.java:836)
    at org.codehaus.groovy.runtime.InvokerHelper.invokeMethod(InvokerHelper.java:827)
    at org.codehaus.groovy.runtime.ScriptBytecodeAdapter.invokeMethodN(ScriptBytecodeAdapter.java:164)
    at org.codehaus.groovy.runtime.ScriptBytecodeAdapter.invokeMethodNSafe(ScriptBytecodeAdapter.java:172)
    at org.codehaus.groovy.runtime.ScriptBytecodeAdapter.invokeMethodNSpreadSafe(ScriptBytecodeAdapter.java:179)
    at com.dtolabs.rundeck.app.internal.workflow.MultiWorkflowExecutionListener.beginWorkflowExecution(MultiWorkflowExecutionListener.groovy:48)
    at com.dtolabs.rundeck.core.execution.workflow.BaseWorkflowStrategy.executeWorkflow(BaseWorkflowStrategy.java:116)
    at com.dtolabs.rundeck.core.execution.WorkflowExecutionServiceThread.run(WorkflowExecutionServiceThread.java:55)
2014-06-25 11:17:32,452 DEBUG DisablingLogWriter - Failed addEvent for StreamingLogWriter(log4jStreamingLogWriterPlugin), disabling. null
java.lang.NullPointerException
    at org.codehaus.groovy.runtime.DefaultGroovyMethods.putAll(DefaultGroovyMethods.java:6184)
    at org.codehaus.groovy.runtime.DefaultGroovyMethods.plus(DefaultGroovyMethods.java:6206)
    at org.codehaus.groovy.runtime.dgm$390.invoke(Unknown Source)
    at org.codehaus.groovy.runtime.callsite.PojoMetaMethodSite$PojoMetaMethodSiteNoUnwrapNoCoerce.invoke(PojoMetaMethodSite.java:271)
    at org.codehaus.groovy.runtime.callsite.PojoMetaMethodSite.call(PojoMetaMethodSite.java:53)
    at org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCall(CallSiteArray.java:45)
    at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:108)
    at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:116)
    at log4jStreamingLogWriterPlugin$_run_closure1_closure7.doCall(log4jStreamingLogWriterPlugin:104)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.codehaus.groovy.runtime.callsite.PogoMetaMethodSite$PogoCachedMethodSiteNoUnwrapNoCoerce.invoke(PogoMetaMethodSite.java:272)
    at org.codehaus.groovy.runtime.callsite.PogoMetaMethodSite.call(PogoMetaMethodSite.java:64)
    at org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCall(CallSiteArray.java:45)
    at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:108)
    at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:120)
    at com.dtolabs.rundeck.server.plugins.builder.ScriptStreamingLogWriterPlugin.addEvent(ScriptStreamingLogWriterPlugin.groovy:74)
    at com.dtolabs.rundeck.core.logging.StreamingLogWriter$addEvent.call(Unknown Source)
    at org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCall(CallSiteArray.java:45)
    at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:108)
    at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:116)
    at rundeck.services.logging.DisablingLogWriter.addEvent(DisablingLogWriter.groovy:42)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:90)
    at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:233)
    at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1082)
    at groovy.lang.ExpandoMetaClass.invokeMethod(ExpandoMetaClass.java:1106)
    at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:906)
    at org.codehaus.groovy.runtime.InvokerHelper.invokePogoMethod(InvokerHelper.java:848)
    at org.codehaus.groovy.runtime.InvokerHelper.invokeMethod(InvokerHelper.java:831)
    at org.codehaus.groovy.runtime.ScriptBytecodeAdapter.invokeMethodN(ScriptBytecodeAdapter.java:164)
    at org.codehaus.groovy.runtime.ScriptBytecodeAdapter.invokeMethodNSafe(ScriptBytecodeAdapter.java:172)
    at org.codehaus.groovy.runtime.ScriptBytecodeAdapter.invokeMethodNSpreadSafe(ScriptBytecodeAdapter.java:179)
    at rundeck.services.logging.MultiLogWriter.addEvent(MultiLogWriter.groovy:29)
    at com.dtolabs.rundeck.core.logging.StreamingLogWriter$addEvent.call(Unknown Source)
    at org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCall(CallSiteArray.java:45)
    at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:108)
    at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:116)
    at rundeck.services.logging.LoglevelThresholdLogWriter.addEvent(LoglevelThresholdLogWriter.groovy:22)
    at com.dtolabs.rundeck.core.logging.FilterStreamingLogWriter.addEvent(FilterStreamingLogWriter.java:21)
    at com.dtolabs.rundeck.core.logging.ContextLogWriter.verbose(ContextLogWriter.java:51)
    at com.dtolabs.rundeck.core.execution.workflow.ContextualExecutionListener.log(ContextualExecutionListener.java:96)
    at com.dtolabs.rundeck.core.execution.workflow.WorkflowExecutionListenerImpl.log(WorkflowExecutionListenerImpl.java:42)
    at com.dtolabs.rundeck.core.execution.workflow.ContextualExecutionListener.log(ContextualExecutionListener.java:60)
    at com.dtolabs.rundeck.core.execution.workflow.WorkflowExecutionListenerImpl.beginWorkflowExecution(WorkflowExecutionListenerImpl.java:159)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:90)
    at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:233)
    at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1082)
    at groovy.lang.ExpandoMetaClass.invokeMethod(ExpandoMetaClass.java:1106)
    at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:906)
    at org.codehaus.groovy.runtime.InvokerHelper.invokePojoMethod(InvokerHelper.java:836)
    at org.codehaus.groovy.runtime.InvokerHelper.invokeMethod(InvokerHelper.java:827)
    at org.codehaus.groovy.runtime.ScriptBytecodeAdapter.invokeMethodN(ScriptBytecodeAdapter.java:164)
    at org.codehaus.groovy.runtime.ScriptBytecodeAdapter.invokeMethodNSafe(ScriptBytecodeAdapter.java:172)
    at org.codehaus.groovy.runtime.ScriptBytecodeAdapter.invokeMethodNSpreadSafe(ScriptBytecodeAdapter.java:179)
    at com.dtolabs.rundeck.app.internal.workflow.MultiWorkflowExecutionListener.beginWorkflowExecution(MultiWorkflowExecutionListener.groovy:48)
    at com.dtolabs.rundeck.core.execution.workflow.BaseWorkflowStrategy.executeWorkflow(BaseWorkflowStrategy.java:116)
    at com.dtolabs.rundeck.core.execution.WorkflowExecutionServiceThread.run(WorkflowExecutionServiceThread.java:55)
gschueler commented 10 years ago

thanks that will help to track down the bug. i will have to get back to you on this a little later.

I did notice the default log4j logger name used by the plugin is not the same as is mentioned in the readme. you should add this config line to framework.properties:

framework.plugin.StreamingLogWriter.log4jStreamingLogWriterPlugin.loggername=org.rundeck.log.event.stream
daneuriona commented 10 years ago

Thanks I appreciate it, I'll give that a try and let you know. I know you've got bigger projects so no rush.

As an update, I just copied the same line twice in the original post, it was like the readme. Updated the original to reflect the actual framework.properties setting.

daneuriona commented 10 years ago

Think I found the problem:

log4j:ERROR Could not find value for key log4j.appender.executionevents
log4j:ERROR Could not instantiate appender named "executionevents".

Seems like log4j.logger.org.rundeck.log.event.stream=info,executionevents,stdout isn't valid because of the executionevents connection.