Velocity log

I am sure this may have been answered before, but I cannot seem to find it. I get some annoying messages in my catalina.out file, which I would rather not see related to DHIS not being able to write to velocity.log.

It seems to want to write this in rather random locations, and I am not even slightly interested in this log. Is there a way to either configure the logging system not to log messages from velocity (there are a bunch), or to simply provide a path to a directory which I actually want the logs to go to?

Regards,
Jason

Hi Jason,

I think the easiest is maybe to tweak the startup script you are running to cd into the log directory before starting tomcat. Then velocity.log will end up there.. If you use ubuntu packages, you can change the existing cd in /etc/init.d/tomcat6 (or the equivalent). Or chmod $CATALINA_BASE, which is where it cd-s to out of the box.

Generally, it is a bit difficult to fix the log setup to write to files other than relatively (since it will vary from place to place), but it should be possible to override the default log4j setup with something like 'export TOMCAT_OPTS="-Dlog4j.configuration=<your log4j config>"',but it is a bit more work to setup... There you could silence velocity logging, route it to sysout or identify the file to log to.

Jo

···

Den 28. okt. 2011 kl. 11.52 skrev Jason Pickering:

I am sure this may have been answered before, but I cannot seem to find it. I get some annoying messages in my catalina.out file, which I would rather not see related to DHIS not being able to write to velocity.log.

It seems to want to write this in rather random locations, and I am not even slightly interested in this log. Is there a way to either configure the logging system not to log messages from velocity (there are a bunch), or to simply provide a path to a directory which I actually want the logs to go to?

Regards,
Jason

_______________________________________________
Mailing list: DHIS 2 developers in Launchpad
Post to : dhis2-devs@lists.launchpad.net
Unsubscribe : DHIS 2 developers in Launchpad
More help : ListHelp - Launchpad Help

Hi Jason,

I think the easiest is maybe to tweak the startup script you are running to cd into the log directory before starting tomcat. Then velocity.log will end up there.. If you use ubuntu packages, you can change the existing cd in /etc/init.d/tomcat6 (or the equivalent). Or chmod $CATALINA_BASE, which is where it cd-s to out of the box.

Generally, it is a bit difficult to fix the log setup to write to files other than relatively (since it will vary from place to place), but it should be possible to override the default log4j setup with something like 'export TOMCAT_OPTS="-Dlog4j.configuration=<your log4j config>"',but it is a bit more work to setup... There you could silence velocity logging, route it to sysout or identify the file to log to.

Shouldn't we somehow handle the velocity log settings in the default
log4j configuration? Before silencing, has anybody ever looked at
what velocity has been trying to say here? I'm a bit curious ...

···

On 28 October 2011 12:44, Jo Størset <storset@gmail.com> wrote:

Jo

Den 28. okt. 2011 kl. 11.52 skrev Jason Pickering:

I am sure this may have been answered before, but I cannot seem to find it. I get some annoying messages in my catalina.out file, which I would rather not see related to DHIS not being able to write to velocity.log.

It seems to want to write this in rather random locations, and I am not even slightly interested in this log. Is there a way to either configure the logging system not to log messages from velocity (there are a bunch), or to simply provide a path to a directory which I actually want the logs to go to?

Regards,
Jason

_______________________________________________
Mailing list: DHIS 2 developers in Launchpad
Post to : dhis2-devs@lists.launchpad.net
Unsubscribe : DHIS 2 developers in Launchpad
More help : ListHelp - Launchpad Help

_______________________________________________
Mailing list: DHIS 2 developers in Launchpad
Post to : dhis2-devs@lists.launchpad.net
Unsubscribe : DHIS 2 developers in Launchpad
More help : ListHelp - Launchpad Help

Likely this should be looked into . Here is a pretty typical one.

http://pastebin.com/cqPGiRT8

Also, there is a whole bunch of stuff in the catalina.out which seems to be related to velocity issues

INFO: RHS of #set statement is null. Context will not be modified. /dhis-web-dataentry/sectionForm.vm [line 70, column 1]
INFO: RHS of #set statement is null. Context will not be modified. /dhis-web-dataentry/sectionForm.vm [line 65, column 1]

INFO: RHS of #set statement is null. Context will not be modified. /dhis-web-dataentry/sectionForm.vm [line 67, column 1]
INFO: RHS of #set statement is null. Context will not be modified. /dhis-web-dataentry/sectionForm.vm [line 70, column 1]

INFO: RHS of #set statement is null. Context will not be modified. /dhis-web-dataentry/sectionForm.vm [line 65, column 1]
INFO: RHS of #set statement is null. Context will not be modified. /dhis-web-dataentry/sectionForm.vm [line 67, column 1]

I think the same issue afflicts the audit.log as well.

I will see if I can go down the log4j route and come up with something.

Regards,
Jason

···

On Fri, Oct 28, 2011 at 1:58 PM, Bob Jolliffe bobjolliffe@gmail.com wrote:

On 28 October 2011 12:44, Jo Størset storset@gmail.com wrote:

Hi Jason,

I think the easiest is maybe to tweak the startup script you are running to cd into the log directory before starting tomcat. Then velocity.log will end up there… If you use ubuntu packages, you can change the existing cd in /etc/init.d/tomcat6 (or the equivalent). Or chmod $CATALINA_BASE, which is where it cd-s to out of the box.

Generally, it is a bit difficult to fix the log setup to write to files other than relatively (since it will vary from place to place), but it should be possible to override the default log4j setup with something like ‘export TOMCAT_OPTS=“-Dlog4j.configuration=”’,but it is a bit more work to setup… There you could silence velocity logging, route it to sysout or identify the file to log to.

Shouldn’t we somehow handle the velocity log settings in the default

log4j configuration? Before silencing, has anybody ever looked at

what velocity has been trying to say here? I’m a bit curious …

Jo

Den 28. okt. 2011 kl. 11.52 skrev Jason Pickering:

I am sure this may have been answered before, but I cannot seem to find it. I get some annoying messages in my catalina.out file, which I would rather not see related to DHIS not being able to write to velocity.log.

It seems to want to write this in rather random locations, and I am not even slightly interested in this log. Is there a way to either configure the logging system not to log messages from velocity (there are a bunch), or to simply provide a path to a directory which I actually want the logs to go to?

Regards,

Jason


Mailing list: https://launchpad.net/~dhis2-devs

Post to : dhis2-devs@lists.launchpad.net

Unsubscribe : https://launchpad.net/~dhis2-devs

More help : https://help.launchpad.net/ListHelp


Mailing list: https://launchpad.net/~dhis2-devs

Post to : dhis2-devs@lists.launchpad.net

Unsubscribe : https://launchpad.net/~dhis2-devs

More help : https://help.launchpad.net/ListHelp

I got the logging setup, sort of. I borrowed much from the dhis-live log4j.properties file, and then attempted to deal with the velocity stuff. My file is here

http://pastebin.com/3yyS8JcZ

which I placed in the DHIS2_HOME directory, and then defined an environment variable to point to this file.

DHIS output goes to where it is supposed to go to, but I get this error

Oct 28, 2011 1:47:01 PM org.apache.velocity.runtime.log.JdkLogChute log

INFO: Failed to initialize an instance of org.apache.velocity.runtime.log.Log4JLogChute with the current runtime configuration.
java.lang.RuntimeException: Error configuring Log4JLogChute :
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)

at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:532)

at org.apache.velocity.util.ExceptionUtils.createWithCause(ExceptionUtils.java:66)
at org.apache.velocity.util.ExceptionUtils.createRuntimeException(ExceptionUtils.java:44)...

which seems to be discussed here…

http://velocity.apache.org/engine/devel/developer-guide.html#usinglog4jwithexistinglogger

Thoughts?

Regards,
Jason

···

On Fri, Oct 28, 2011 at 2:08 PM, Jason Pickering jason.p.pickering@gmail.com wrote:

Likely this should be looked into . Here is a pretty typical one.

http://pastebin.com/cqPGiRT8

Also, there is a whole bunch of stuff in the catalina.out which seems to be related to velocity issues

INFO: RHS of #set statement is null. Context will not be modified. /dhis-web-dataentry/sectionForm.vm [line 70, column 1]
INFO: RHS of #set statement is null. Context will not be modified. /dhis-web-dataentry/sectionForm.vm [line 65, column 1]

INFO: RHS of #set statement is null. Context will not be modified. /dhis-web-dataentry/sectionForm.vm [line 67, column 1]
INFO: RHS of #set statement is null. Context will not be modified. /dhis-web-dataentry/sectionForm.vm [line 70, column 1]

INFO: RHS of #set statement is null. Context will not be modified. /dhis-web-dataentry/sectionForm.vm [line 65, column 1]
INFO: RHS of #set statement is null. Context will not be modified. /dhis-web-dataentry/sectionForm.vm [line 67, column 1]

I think the same issue afflicts the audit.log as well.

I will see if I can go down the log4j route and come up with something.

Regards,
Jason

On Fri, Oct 28, 2011 at 1:58 PM, Bob Jolliffe bobjolliffe@gmail.com wrote:

On 28 October 2011 12:44, Jo Størset storset@gmail.com wrote:

Hi Jason,

I think the easiest is maybe to tweak the startup script you are running to cd into the log directory before starting tomcat. Then velocity.log will end up there… If you use ubuntu packages, you can change the existing cd in /etc/init.d/tomcat6 (or the equivalent). Or chmod $CATALINA_BASE, which is where it cd-s to out of the box.

Generally, it is a bit difficult to fix the log setup to write to files other than relatively (since it will vary from place to place), but it should be possible to override the default log4j setup with something like ‘export TOMCAT_OPTS=“-Dlog4j.configuration=”’,but it is a bit more work to setup… There you could silence velocity logging, route it to sysout or identify the file to log to.

Shouldn’t we somehow handle the velocity log settings in the default

log4j configuration? Before silencing, has anybody ever looked at

what velocity has been trying to say here? I’m a bit curious …

Jo

Den 28. okt. 2011 kl. 11.52 skrev Jason Pickering:

I am sure this may have been answered before, but I cannot seem to find it. I get some annoying messages in my catalina.out file, which I would rather not see related to DHIS not being able to write to velocity.log.

It seems to want to write this in rather random locations, and I am not even slightly interested in this log. Is there a way to either configure the logging system not to log messages from velocity (there are a bunch), or to simply provide a path to a directory which I actually want the logs to go to?

Regards,

Jason


Mailing list: https://launchpad.net/~dhis2-devs

Post to : dhis2-devs@lists.launchpad.net

Unsubscribe : https://launchpad.net/~dhis2-devs

More help : https://help.launchpad.net/ListHelp


Mailing list: https://launchpad.net/~dhis2-devs

Post to : dhis2-devs@lists.launchpad.net

Unsubscribe : https://launchpad.net/~dhis2-devs

More help : https://help.launchpad.net/ListHelp

Yes, bad thoughts about the velocity developers... Seriously, I just gave up and do a cd into the log dir. Though, as Bob would say, it is not "the right solution", so if anyone else fixes this, please let me know :slight_smile:

Jo

···

Den 28. okt. 2011 kl. 16.53 skrev Jason Pickering:

Thoughts?

Okay but in the context of an ubuntu package installer, is this such a good idea? Then we need to hack some startup scripts from the package i would presume which defeats the purpose.

I will continue to dig but it would seem we should just nullify this output entirely for production installs.

Regards,

Jason

···

On Oct 28, 2011 5:42 PM, “Jo Størset” storset@gmail.com wrote:

Den 28. okt. 2011 kl. 16.53 skrev Jason Pickering:

Thoughts?

Yes, bad thoughts about the velocity developers… Seriously, I just gave up and do a cd into the log dir. Though, as Bob would say, it is not “the right solution”, so if anyone else fixes this, please let me know :slight_smile:

Jo

Okay but in the context of an ubuntu package installer, is this such a good idea? Then we need to hack some startup scripts from the package i would presume which defeats the purpose.

In the setups I've done lately I've had several tomcat instances, so some tweaking of the packaged stuff has been necessary anyway. But yes, it does defeat the purpose of completely automated package updates..

I will continue to dig but it would seem we should just nullify this output entirely for production installs.

I guess either that or just allowing it to log to CATALINA_BASE, if you don't want to touch init files...

Jo

···

Den 28. okt. 2011 kl. 17.53 skrev Jason Pickering:

I tried out a few things, and it seems to be related to the init of velocity.

The initial errors related to the velocity.log can be relieved with the following diff, although I never actually see this file appear anywhere.

These errors occur before the initial start-up procedures commence.

There is a second round of errors which occur, after the server startup, which I cannot get rid of.

which can be seen here http://pastebin.com/bRjmw5uh

This seems to be another problem, possibly related to some other VelocityManager not being inited properly .

This is a relatively minor issue, but we should solve it to prevent all of this crap from appearing unnecessarily in production logs.

Regards,
Jason

=== modified file ‘dhis-2/dhis-support/dhis-support-system/src/main/java/org/his
p/dhis/system/velocity/VelocityManager.java’
— dhis-2/dhis-support/dhis-support-system/src/main/java/org/hisp/dhis/system/v

elocity/VelocityManager.java 2011-10-07 10:08:02 +0000
+++ dhis-2/dhis-support/dhis-support-system/src/main/java/org/hisp/dhis/system/v
elocity/VelocityManager.java 2011-10-29 15:03:16 +0000
@@ -33,6 +33,10 @@

import org.apache.velocity.app.Velocity;
import org.apache.velocity.app.VelocityEngine;
import org.apache.velocity.runtime.resource.loader.ClasspathResourceLoader;
+import org.apache.velocity.runtime.RuntimeConstants;

···

+import org.apache.log4j.Logger;
+import org.apache.log4j.BasicConfigurator;

public class VelocityManager
{
@@ -42,20 +46,34 @@
private static final String VM_SUFFIX = “.vm”;
private VelocityEngine velocity;

  • public static String LOGGER_NAME = “dhis2-velocity.log”;

  • public VelocityManager() throws Exception
    {

  •    //Maybe we should just nuke this log completely?
    
  •    //java.util.Properties p = new java.util.Properties();
    
  •   // p.setProperty("runtime.log.logsystem.class", "org.apache.velocity.run
    

time.log.NullLogSystem");
+

  •    BasicConfigurator.configure();
    
  •    Logger log = Logger.getLogger ( LOGGER_NAME );
    
  •    [log.info](http://log.info)("Starting velocity log");
    
  •    velocity = new VelocityEngine();
       velocity.setProperty( Velocity.RESOURCE_LOADER, RESOURCE_LOADER_NAME );
    
       velocity.setProperty( RESOURCE_LOADER_NAME + ".resource.loader.class",
    

ClasspathResourceLoader.class.getName() );

  •    velocity.setProperty( RuntimeConstants.RUNTIME_LOG_LOGSYSTEM_CLASS, "or
    

g.apache.velocity.runtime.log.Log4JLogChute" );

  •    velocity.setProperty("runtime.log.logsystem.log4j.logger",LOGGER_NAME);
    
       velocity.init();
    
  • }
  •    [log.info](http://log.info)("follows initialization output from velocity");
    
  •    }
    
 public String render( Object object, String template )
 {
     try
     {
         StringWriter writer = new StringWriter();
  •        VelocityContext context = new VelocityContext();
    
           if ( object != null )
    

hi,

the velocity manager is a new addition used in places where we use velocity on our own, and as you show is prbably easy enough to fix. It will probably be a bit more cumbersome to override struts' initalization of velocity, and I'm not sure it is worth the effort..

Jo

I agree, it is a minor issue. It is just annoying when trawling through logs to see all this stuff which seemingly we have no use for, and no control over (especially in production environments)

The diff I sent, along with the addition of a velocity.properties file in WEB-INF/classes with content

runtime.log.logsystem.class=org.apache.velocity.runtime.log.SimpleLog4JLogSystem

runtime.log.logsystem.log4j.category=velocity

stops the initial error from happening as well as the other error I detailed in the log.

I will prepare a patch and send to Lars/Jo/Bob for consideration.

Regards,
Jason

···

On Sat, Oct 29, 2011 at 8:00 PM, Jo Størset storset@gmail.com wrote:

hi,

the velocity manager is a new addition used in places where we use velocity on our own, and as you show is prbably easy enough to fix. It will probably be a bit more cumbersome to override struts’ initalization of velocity, and I’m not sure it is worth the effort…

Jo

Jason appreciate the investigation you are doing here. I think it's
important that we handle these things well.

···

On 29 October 2011 20:18, Jason Pickering <jason.p.pickering@gmail.com> wrote:

I agree, it is a minor issue. It is just annoying when trawling through logs
to see all this stuff which seemingly we have no use for, and no control
over (especially in production environments)

The diff I sent, along with the addition of a velocity.properties file in
WEB-INF/classes with content

runtime.log.logsystem.class=org.apache.velocity.runtime.log.SimpleLog4JLogSystem
runtime.log.logsystem.log4j.category=velocity

stops the initial error from happening as well as the other error I detailed
in the log.

I will prepare a patch and send to Lars/Jo/Bob for consideration.
Regards,
Jason

On Sat, Oct 29, 2011 at 8:00 PM, Jo Størset <storset@gmail.com> wrote:

hi,

the velocity manager is a new addition used in places where we use
velocity on our own, and as you show is prbably easy enough to fix. It will
probably be a bit more cumbersome to override struts' initalization of
velocity, and I'm not sure it is worth the effort..

Jo

OK, this patch seems to do the trick for me. DHIS has suddenly become very quiet.

There are some bad things about this patch, namely that velocity is init-ed in two places…VelocityManager and GridUtils. I did not want to start to refactor GridUtils, so I basically put the same code in two places. Seems like something else to be cleaned up, but I did not want to get into it. I have added the velocity.properties file, through which you should be able to specify the logging mechanism. Also, the default velocity logger is set to org.apache.velocity.runtime.log.NullLogSystem unless DEBUG logging is turned on. I have not tested whether the debugging actually works, but maybe the points I wanted are clear, and someone can clean the rest up as it should be.

Cheers,
Jason

velocity_logging_cleanup.patch (6.33 KB)

···

On Sat, Oct 29, 2011 at 10:47 PM, Bob Jolliffe bobjolliffe@gmail.com wrote:

Jason appreciate the investigation you are doing here. I think it’s

important that we handle these things well.

On 29 October 2011 20:18, Jason Pickering jason.p.pickering@gmail.com wrote:

I agree, it is a minor issue. It is just annoying when trawling through logs

to see all this stuff which seemingly we have no use for, and no control

over (especially in production environments)

The diff I sent, along with the addition of a velocity.properties file in

WEB-INF/classes with content

runtime.log.logsystem.class=org.apache.velocity.runtime.log.SimpleLog4JLogSystem

runtime.log.logsystem.log4j.category=velocity

stops the initial error from happening as well as the other error I detailed

in the log.

I will prepare a patch and send to Lars/Jo/Bob for consideration.

Regards,

Jason

On Sat, Oct 29, 2011 at 8:00 PM, Jo Størset storset@gmail.com wrote:

hi,

the velocity manager is a new addition used in places where we use

velocity on our own, and as you show is prbably easy enough to fix. It will

probably be a bit more cumbersome to override struts’ initalization of

velocity, and I’m not sure it is worth the effort…

Jo

Fixed. Did a minor tweak to send the logging to the standard log.