Logging (for server administrators)

Hi there,

the way application logging (e.g. tomcat logging) in DHIS 2 worked up to now has not been ideal. Basically all log output has been sent to std out. For the tomcat container this means all logging has ended up in catalina.out under tomcat install dir > logs.

This is not great since there is no simple way (beside using logrotate or other tools) to control the size of the log file or to specify custom locations for DHIS 2-related log content. This could cause a server to uncontrollably run out of disk space.

In DHIS 2.19 this has changed so that DHIS 2-related log output is sent to the DHIS2_HOME location /logs (this is where you e.g. keep the hibernate.properties file, set by an env variable). The system also separates log output for the main background processes such as analytics table generation and import-export into separate files, so that you can easily look up errors/output for these without having to skim through lots of other content. So we now have 4 log files:

<DHIS2_HOME>/logs/dhis.log

<DHIS2_HOME>/logs/dhis-analytics-table.log

<DHIS2_HOME>/logs/dhis-data-exchange.log

<DHIS2_HOME>/logs/dhis-data-sync.log

You can read more in the docs here:

https://www.dhis2.org/doc/snapshot/en/implementer/html/ch08s07.html

The system currently still logs to std out, as we wanted to introduce this gradually and not cause confusion.

In 2.20 we plan to stop logging to std out (catalina.out) completely, and only use the log files under DHIS2_HOME.

I am interested to hear if people are comfortable with this and if it sounds like a good solution.

regards,

Lars

I think this is a good idea – it can be quite problematic managing log files on large servers.

………………………………………

Regards,

Dapo Adejumo

+2348033683677

Skype : dapojorge

···

From: Dhis2-devs [mailto:dhis2-devs-bounces+dapsyjorge=gmail.com@lists.launchpad.net] On Behalf Of Lars Helge Øverland
Sent: 7 June, 2015 12:33 PM
To: DHIS 2 Developers list; DHIS 2 Users list
Subject: [Dhis2-devs] logging (for server administrators)

Hi there,

the way application logging (e.g. tomcat logging) in DHIS 2 worked up to now has not been ideal. Basically all log output has been sent to std out. For the tomcat container this means all logging has ended up in catalina.out under tomcat install dir > logs.

This is not great since there is no simple way (beside using logrotate or other tools) to control the size of the log file or to specify custom locations for DHIS 2-related log content. This could cause a server to uncontrollably run out of disk space.

In DHIS 2.19 this has changed so that DHIS 2-related log output is sent to the DHIS2_HOME location /logs (this is where you e.g. keep the hibernate.properties file, set by an env variable). The system also separates log output for the main background processes such as analytics table generation and import-export into separate files, so that you can easily look up errors/output for these without having to skim through lots of other content. So we now have 4 log files:

<DHIS2_HOME>/logs/dhis.log

<DHIS2_HOME>/logs/dhis-analytics-table.log

<DHIS2_HOME>/logs/dhis-data-exchange.log

<DHIS2_HOME>/logs/dhis-data-sync.log

You can read more in the docs here:

https://www.dhis2.org/doc/snapshot/en/implementer/html/ch08s07.html

The system currently still logs to std out, as we wanted to introduce this gradually and not cause confusion.

In 2.20 we plan to stop logging to std out (catalina.out) completely, and only use the log files under DHIS2_HOME.

I am interested to hear if people are comfortable with this and if it sounds like a good solution.

regards,

Lars

Lars this seems like a good development to me. I presume we will
still be able to override with an external log4j config. Sometimes
its more convenient to rotate by time (eg month) than by size.

I presume all the exception dumps (ie not "real" logs) are going to
end up in catalina which is fine. We can work on catching them piece
by piece.

···

On 7 June 2015 at 12:33, Lars Helge Øverland <larshelge@gmail.com> wrote:

Hi there,

the way application logging (e.g. tomcat logging) in DHIS 2 worked up to now
has not been ideal. Basically all log output has been sent to std out. For
the tomcat container this means all logging has ended up in catalina.out
under tomcat install dir > logs.

This is not great since there is no simple way (beside using logrotate or
other tools) to control the size of the log file or to specify custom
locations for DHIS 2-related log content. This could cause a server to
uncontrollably run out of disk space.

In DHIS 2.19 this has changed so that DHIS 2-related log output is sent to
the DHIS2_HOME location /logs (this is where you e.g. keep the
hibernate.properties file, set by an env variable). The system also
separates log output for the main background processes such as analytics
table generation and import-export into separate files, so that you can
easily look up errors/output for these without having to skim through lots
of other content. So we now have 4 log files:

<DHIS2_HOME>/logs/dhis.log
<DHIS2_HOME>/logs/dhis-analytics-table.log
<DHIS2_HOME>/logs/dhis-data-exchange.log
<DHIS2_HOME>/logs/dhis-data-sync.log

You can read more in the docs here:

https://www.dhis2.org/doc/snapshot/en/implementer/html/ch08s07.html

The system currently still logs to std out, as we wanted to introduce this
gradually and not cause confusion.

In 2.20 we plan to stop logging to std out (catalina.out) completely, and
only use the log files under DHIS2_HOME.

I am interested to hear if people are comfortable with this and if it sounds
like a good solution.

regards,

Lars

_______________________________________________
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

Thanks Bob and Dapo.

···

On Sun, Jun 7, 2015 at 3:50 PM, Bob Jolliffe bobjolliffe@gmail.com wrote:

Lars this seems like a good development to me. I presume we will

still be able to override with an external log4j config. Sometimes

its more convenient to rotate by time (eg month) than by size.

Yes definitely. I will remove the log4j.properties that is bundled with DHIS 2, however you can of course include you own inside tomcat which allows system admins to configure logging according to their preferences. The new solution is aimed at providing a sensible out-of-the-box setup to avoid running out of disk space, easily finding analytics table issues, etc.

I presume all the exception dumps (ie not “real” logs) are going to

end up in catalina which is fine. We can work on catching them piece

by piece.

No everything generated by DHIS 2 including exceptions go into the main dhis.log file. We should of course aim at fixing the cause of these errors.

Lars

Is there an easy way to switch this off during development? Having to tail
an extra log file every time doesn't sounds very convenient..

···

On Sun, Jun 7, 2015 at 10:37 PM, Lars Helge Øverland <larshelge@gmail.com> wrote:

No everything generated by DHIS 2 including exceptions go into the main
dhis.log file. We should of course aim at fixing the cause of these errors.

--
Morten

If the log4j config is overridable at launch we could always add a property pointing to a development config in the maven dev profile. I’m not sure how that would play with this though as it’s being configured programmatically at application startup.

Thoughts Lars?

···

2015-06-08 3:45 GMT+02:00 Morten Olav Hansen mortenoh@gmail.com:


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

On Sun, Jun 7, 2015 at 10:37 PM, Lars Helge Øverland larshelge@gmail.com wrote:

No everything generated by DHIS 2 including exceptions go into the main dhis.log file. We should of course aim at fixing the cause of these errors.

Is there an easy way to switch this off during development? Having to tail an extra log file every time doesn’t sounds very convenient…


Morten

Ah!! I have just noticed that this new logging regime is actually
hardcoded in java. That strikes me as a really bad idea. Can we not
achieve exactly the same effect as you get in code by providing a
default log4j.xml file bundled in the war which could be overriden by
an external file.

Whereas having a sensible out-of-the-box logging setup makes sense, I
can't really see any benefit at all in doing this with code rather
than configuration. What I would rather do, for example, is to have a
log4j config file bundled with dhis2-tools which is maybe a copy of
the default config. Then implementers could tweak if they saw fit.
Similar with devs or docker folk who might want to fall back to
catalina.out.

What is the reason for configuring the logging with compiled code? Is
it just to to specify the default logging location based on
DHIS2_HOME?

···

On 8 June 2015 at 13:06, Halvdan Grelland <halvdanhg@gmail.com> wrote:

If the log4j config is overridable at launch we could always add a property
pointing to a development config in the maven dev profile. I'm not sure how
that would play with this though as it's being configured programmatically
at application startup.

Thoughts Lars?

2015-06-08 3:45 GMT+02:00 Morten Olav Hansen <mortenoh@gmail.com>:

On Sun, Jun 7, 2015 at 10:37 PM, Lars Helge Øverland <larshelge@gmail.com> >> wrote:

No everything generated by DHIS 2 including exceptions go into the main
dhis.log file. We should of course aim at fixing the cause of these errors.

Is there an easy way to switch this off during development? Having to tail
an extra log file every time doesn't sounds very convenient..

--
Morten

_______________________________________________
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

Maybe a better approach would be to upgrade log4j 1.2.7 to log4j 2 -
which allows for example to refer to envronment variables (like
DHIS2_HOME) in the configuration.

···

On 8 June 2015 at 13:37, Bob Jolliffe <bobjolliffe@gmail.com> wrote:

Ah!! I have just noticed that this new logging regime is actually
hardcoded in java. That strikes me as a really bad idea. Can we not
achieve exactly the same effect as you get in code by providing a
default log4j.xml file bundled in the war which could be overriden by
an external file.

Whereas having a sensible out-of-the-box logging setup makes sense, I
can't really see any benefit at all in doing this with code rather
than configuration. What I would rather do, for example, is to have a
log4j config file bundled with dhis2-tools which is maybe a copy of
the default config. Then implementers could tweak if they saw fit.
Similar with devs or docker folk who might want to fall back to
catalina.out.

What is the reason for configuring the logging with compiled code? Is
it just to to specify the default logging location based on
DHIS2_HOME?

On 8 June 2015 at 13:06, Halvdan Grelland <halvdanhg@gmail.com> wrote:

If the log4j config is overridable at launch we could always add a property
pointing to a development config in the maven dev profile. I'm not sure how
that would play with this though as it's being configured programmatically
at application startup.

Thoughts Lars?

2015-06-08 3:45 GMT+02:00 Morten Olav Hansen <mortenoh@gmail.com>:

On Sun, Jun 7, 2015 at 10:37 PM, Lars Helge Øverland <larshelge@gmail.com> >>> wrote:

No everything generated by DHIS 2 including exceptions go into the main
dhis.log file. We should of course aim at fixing the cause of these errors.

Is there an easy way to switch this off during development? Having to tail
an extra log file every time doesn't sounds very convenient..

--
Morten

_______________________________________________
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

I just had a quick check of log4j 2. Upgrading seems as
straightforward as replacing the 1.2.7 dependency with:

      <dependency>
        <groupId>org.apache.logging.log4j</groupId>
        <artifactId>log4j-api</artifactId>
        <version>2.3</version>
      </dependency>
      <dependency>
        <groupId>org.apache.logging.log4j</groupId>
        <artifactId>log4j-core</artifactId>
        <version>2.3</version>
      </dependency>
      <dependency>
        <groupId>org.apache.logging.log4j</groupId>
        <artifactId>log4j-1.2-api</artifactId>
        <version>2.3</version>
      </dependency>

Note the last dependency just provides an adaptor so the old log4j
code will still work (except for programmatic configuration).
Providing a config file for the new settings does seem much better
than hard coding them. One very useful feature I see in log4j 2
(besides the ability to use env variables and system properties in the
config file) is the ability to reload the log4j configuration without
restarting the server. See "Configuration Syntax" monitorInterval at
http://logging.apache.org/log4j/2.x/manual/configuration.html\.
That's something I've often wished for.

Can I ask again .. is the main reason for doing this programatically
so that we can direct logging to DHIS2_HOME? If so, then let's do it
this way instead.

···

On 8 June 2015 at 13:42, Bob Jolliffe <bobjolliffe@gmail.com> wrote:

Maybe a better approach would be to upgrade log4j 1.2.7 to log4j 2 -
which allows for example to refer to envronment variables (like
DHIS2_HOME) in the configuration.

On 8 June 2015 at 13:37, Bob Jolliffe <bobjolliffe@gmail.com> wrote:

Ah!! I have just noticed that this new logging regime is actually
hardcoded in java. That strikes me as a really bad idea. Can we not
achieve exactly the same effect as you get in code by providing a
default log4j.xml file bundled in the war which could be overriden by
an external file.

Whereas having a sensible out-of-the-box logging setup makes sense, I
can't really see any benefit at all in doing this with code rather
than configuration. What I would rather do, for example, is to have a
log4j config file bundled with dhis2-tools which is maybe a copy of
the default config. Then implementers could tweak if they saw fit.
Similar with devs or docker folk who might want to fall back to
catalina.out.

What is the reason for configuring the logging with compiled code? Is
it just to to specify the default logging location based on
DHIS2_HOME?

On 8 June 2015 at 13:06, Halvdan Grelland <halvdanhg@gmail.com> wrote:

If the log4j config is overridable at launch we could always add a property
pointing to a development config in the maven dev profile. I'm not sure how
that would play with this though as it's being configured programmatically
at application startup.

Thoughts Lars?

2015-06-08 3:45 GMT+02:00 Morten Olav Hansen <mortenoh@gmail.com>:

On Sun, Jun 7, 2015 at 10:37 PM, Lars Helge Øverland <larshelge@gmail.com> >>>> wrote:

No everything generated by DHIS 2 including exceptions go into the main
dhis.log file. We should of course aim at fixing the cause of these errors.

Is there an easy way to switch this off during development? Having to tail
an extra log file every time doesn't sounds very convenient..

--
Morten

_______________________________________________
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

Hi Bob,

thanks for the feedback.

Yes the main reason for having a java based default config is to be able to set the log file path to the dhis home directory. Yes the env var support in log4j 2 is cool but it is not sufficient in our use case since dhis config loading is more complex - it looks for 1) a system property dhis2.home, 2) an env variable DHIS2_HOME and 3) eventually falls back to using /opt/dhis2. I know DHIS 2 Live uses 2) and I know many deployments which use 3). So there is no guarantee that DHIS2_HOME is set, hence it is not a reliable solution.

Re XML vs config files - config files are more flexible in general but in this scenario it makes no difference. In any case you don’t want to modify or remove config files which are bundled inside the WAR file since those changes will be wiped next time the WAR is upgraded, but rather append / override it with an external file. You can have your external file override the default DHIS 2 config, irrespective of that default config being set in Java or from a config file.

regards,

Lars

Hi Lars

Hi Bob,

thanks for the feedback.

Yes the main reason for having a java based default config is to be able to
set the log file path to the dhis home directory. Yes the env var support in
log4j 2 is cool but it is not sufficient in our use case since dhis config
loading is more complex - it looks for 1) a system property dhis2.home, 2)
an env variable DHIS2_HOME and 3) eventually falls back to using
<user-home-dir>/opt/dhis2. I know DHIS 2 Live uses 2) and I know many
deployments which use 3). So there is no guarantee that DHIS2_HOME is set,
hence it is not a reliable solution.

I suspect both these use cases are not as valid as they once were.
dhis2-live provides its own log4j.properties file anyway so wouldn't
be an issue. And (3) which uses /opt/dhis2 is a hangover from a bad
idea of mine for packaging a deb. I am not sure i would recommend it
at all - but would rather just simplify the code in dhis2 back to the
env variable. Anyway, see below ...

Re XML vs config files - config files are more flexible in general but in
this scenario it makes no difference. In any case you don't want to modify
or remove config files which are bundled inside the WAR file since those
changes will be wiped next time the WAR is upgraded, but rather append /
override it with an external file. You can have your external file override
the default DHIS 2 config, irrespective of that default config being set in
Java or from a config file.

That is the important point. I assumed that if you were configuring
in java that you would not be able to override those settings with an
external config file (I wasn't planning to fiddle with the internal
one). Has anyone tried this? If it is indeed the case that it can be
overridden then of course it makes no difference at all what the java
code does or doesn't do which is fine. Except of course having all
this in code does make moving (eg to log4j 2) a bit more difficult.

···

On 9 June 2015 at 07:37, Lars Helge Øverland <larshelge@gmail.com> wrote:

I just tried - you can't override those settings with an external
file. They will always kick in after the configuration is loaded.
Which is very inflexible. For example even the logging level is
fixed.

I think its worth reconsidering.

···

On 9 June 2015 at 09:00, Bob Jolliffe <bobjolliffe@gmail.com> wrote:

Hi Lars

On 9 June 2015 at 07:37, Lars Helge Øverland <larshelge@gmail.com> wrote:

Hi Bob,

thanks for the feedback.

Yes the main reason for having a java based default config is to be able to
set the log file path to the dhis home directory. Yes the env var support in
log4j 2 is cool but it is not sufficient in our use case since dhis config
loading is more complex - it looks for 1) a system property dhis2.home, 2)
an env variable DHIS2_HOME and 3) eventually falls back to using
<user-home-dir>/opt/dhis2. I know DHIS 2 Live uses 2) and I know many
deployments which use 3). So there is no guarantee that DHIS2_HOME is set,
hence it is not a reliable solution.

I suspect both these use cases are not as valid as they once were.
dhis2-live provides its own log4j.properties file anyway so wouldn't
be an issue. And (3) which uses /opt/dhis2 is a hangover from a bad
idea of mine for packaging a deb. I am not sure i would recommend it
at all - but would rather just simplify the code in dhis2 back to the
env variable. Anyway, see below ...

Re XML vs config files - config files are more flexible in general but in
this scenario it makes no difference. In any case you don't want to modify
or remove config files which are bundled inside the WAR file since those
changes will be wiped next time the WAR is upgraded, but rather append /
override it with an external file. You can have your external file override
the default DHIS 2 config, irrespective of that default config being set in
Java or from a config file.

That is the important point. I assumed that if you were configuring
in java that you would not be able to override those settings with an
external config file (I wasn't planning to fiddle with the internal
one). Has anyone tried this? If it is indeed the case that it can be
overridden then of course it makes no difference at all what the java
code does or doesn't do which is fine. Except of course having all
this in code does make moving (eg to log4j 2) a bit more difficult.

In order to override log4j default initialization you can set the
log4j.configuration system property to point to another resource (e.g. in
your dhis2-tools scripts).

This applies whether the default config is set in Java or through a config
file.

See the docs here <http://logging.apache.org/log4j/1.2/manual.html&gt;, scroll
to "Default Initialization Procedure".

Lars

···

On Tue, Jun 9, 2015 at 11:19 AM, Bob Jolliffe <bobjolliffe@gmail.com> wrote:

I just tried - you can't override those settings with an external
file. They will always kick in after the configuration is loaded.
Which is very inflexible. For example even the logging level is
fixed.

I think its worth reconsidering.

Yes that is what I just tested. It loads the log4 configuration file.
But this doesn't prevent the java code from running so it configures
twice.

···

On 9 June 2015 at 10:38, Lars Helge Øverland <larshelge@gmail.com> wrote:

On Tue, Jun 9, 2015 at 11:19 AM, Bob Jolliffe <bobjolliffe@gmail.com> wrote:

I just tried - you can't override those settings with an external
file. They will always kick in after the configuration is loaded.
Which is very inflexible. For example even the logging level is
fixed.

I think its worth reconsidering.

In order to override log4j default initialization you can set the
log4j.configuration system property to point to another resource (e.g. in
your dhis2-tools scripts).

This applies whether the default config is set in Java or through a config
file.

See the docs here, scroll to "Default Initialization Procedure".

Lars

Okay that’s weird. If so I can look for “log4j.configuration” i the java config loader and exit if that system prop is present?

···

On Tue, Jun 9, 2015 at 11:48 AM, Bob Jolliffe bobjolliffe@gmail.com wrote:

Yes that is what I just tested. It loads the log4 configuration file.

But this doesn’t prevent the java code from running so it configures

twice.

On 9 June 2015 at 10:38, Lars Helge Øverland larshelge@gmail.com wrote:

On Tue, Jun 9, 2015 at 11:19 AM, Bob Jolliffe bobjolliffe@gmail.com wrote:

I just tried - you can’t override those settings with an external

file. They will always kick in after the configuration is loaded.

Which is very inflexible. For example even the logging level is

fixed.

I think its worth reconsidering.

In order to override log4j default initialization you can set the

log4j.configuration system property to point to another resource (e.g. in

your dhis2-tools scripts).

This applies whether the default config is set in Java or through a config

file.

See the docs here, scroll to “Default Initialization Procedure”.

Lars

Lars Helge Øverland

Lead developer, DHIS 2

University of Oslo

Skype: larshelgeoverland

http://www.dhis2.org

For the record I did a small fix to abort the default log config when an
external config file is configured based on Bob's feedback. Updated docs
here <https://www.dhis2.org/doc/snapshot/en/implementer/html/ch08s07.html&gt;\.

···

On Tue, Jun 9, 2015 at 11:48 AM, Bob Jolliffe <bobjolliffe@gmail.com> wrote:

Yes that is what I just tested. It loads the log4 configuration file.
But this doesn't prevent the java code from running so it configures
twice.