You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@maven.apache.org by e7a7b7 <ry...@oracle.com> on 2008/03/14 19:11:41 UTC

getting timestamps in console logging output

Hello all,

Thanks for hosting a great forum.  I have scoured this forum for the answer
to this question, and while there seem to be many logging- and log4j-related
questions and answers, I have been unable to figure out how to do what I'm
trying to do, which is to add timestamps to the maven console output.

For example, I want this:
[INFO]
------------------------------------------------------------------------
[INFO] BUILD SUCCESSFUL
[INFO]
------------------------------------------------------------------------

to look instead like this:
[2008-03-14 11:20:03,312 INFO]
------------------------------------------------------------------------
[2008-03-14 11:20:03,312 INFO] BUILD SUCCESSFUL
[2008-03-14 11:20:03,312 INFO]
------------------------------------------------------------------------

The reason for wanting this is that we are trying to tune our build and
measure our success by looking at the time each build step takes.

My understanding is that maven uses log4j/commons-logging, both of which I'm
familiar with.  I then tried to plug a custom log4j.properties into the
right location on the classpath to achieve what I wanted.  I tried setting
the following on both command-line and by altering MAVEN_OPTS in mvn.bat:

-Dlog4j.debug=true -Dlog4j.configuration=file:/c:/log4j.properties

Neither approach has any effect--I get no log4j debug information, and my
properties file is ignored.  I also tried putting the log4j.properties in
the current directory of the build--this doesn't work either.  Nothing I did
seemed able to trigger log4j debug info, making me suspicious as to whether
log4j was even in use.

I took a quick glance at the maven source code, but was unsuccessful in
locating the logging module to try and trace how the log configuration is
initialized.

Anybody know how to customize the "layout" of the maven console output? 
Thanks in advance for any pointers.

--Ryan

P.S. Just to avoid any off-topic responses, note that my junit test output
is correctly using a custom log4j.properties (from test/resources, etc.). 
However, this is not my objective--I'm trying to customize all maven console
output.


-- 
View this message in context: http://www.nabble.com/getting-timestamps-in-console-logging-output-tp16048940s177p16048940.html
Sent from the Maven - Users mailing list archive at Nabble.com.


---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@maven.apache.org
For additional commands, e-mail: users-help@maven.apache.org


RE: getting timestamps in console logging output

Posted by Richard Chamberlain <ri...@caplin.com>.
Could you not create a maven-timing plugin and get it to print out the
current time to the console. This way you could insert it into various
points of the build and analyse which parts are slow.

I appreciate it is not ideal!

Richard

-----Original Message-----
From: e7a7b7 [mailto:ryan.golden@oracle.com] 
Sent: 14 March 2008 22:41
To: users@maven.apache.org
Subject: Re: getting timestamps in console logging output


Thanks for your response, although I wonder if anybody else has any
additional suggestions?

As per the reason for wanting to time build steps, some background: our
build system is actually a very mature, highly-modularized maven system.
We
use an internal remote repository and have a continuous integration
system
running that is continually updating the repository.

Modularity in some ways actually contributes to the performance issues
we
are having, since we build a large number of GWT war artifacts with the
gwt-maven-plugin.  For those unfamilar, the GWT-maven-plugin generates a
complete webapp from java code.  The GWT compilation is relatively slow
and
not highly configurable.  The wars created are "correct" but somewhat
large. 
Shuttling large war files back and forth to the internal repository with
each local build and performing large war overlay operations can be very
slow, and we've tried a number of different techniques to lower the I/O
requirements, including using custom ant steps to pare down the size of
the
war artifacts.

Anyway, we are trying to further tune 1) the gwt-maven-plugin and 2) the
war
creation/overlay steps to get the maximum performance out of the build. 
Since these steps are somewhat related, it's difficult to measure the
impact
of changes without having time stats on each output line.

If anybody has any further suggestions, or can explain anything about
how
maven loads its logging configuration, they would be appreciated.
Thanks
again.

--Ryan


Wayne Fay wrote:
> 
> Without knowing for sure but basing my answer on my own reading and
> research into customizing things like this in Maven2, I believe the
> answer is "this is not possible with 2.0.x".
> 
> How long is your build such that this is even an issue? You should
> break things up into small modules so they all build quickly -- then
> you can time those individual module builds and monitor their times
> etc if you really must. If you have a huge monolithic build that takes
> forever, you're probably doing things wrong.
> 
> Wayne
> 
> On 3/14/08, e7a7b7 <ry...@oracle.com> wrote:
>>
>> Hello all,
>>
>> Thanks for hosting a great forum.  I have scoured this forum for the
>> answer
>> to this question, and while there seem to be many logging- and
>> log4j-related
>> questions and answers, I have been unable to figure out how to do
what
>> I'm
>> trying to do, which is to add timestamps to the maven console output.
>>
>> For example, I want this:
>> [INFO]
>>
------------------------------------------------------------------------
>> [INFO] BUILD SUCCESSFUL
>> [INFO]
>>
------------------------------------------------------------------------
>>
>> to look instead like this:
>> [2008-03-14 11:20:03,312 INFO]
>>
------------------------------------------------------------------------
>> [2008-03-14 11:20:03,312 INFO] BUILD SUCCESSFUL
>> [2008-03-14 11:20:03,312 INFO]
>>
------------------------------------------------------------------------
>>
>> The reason for wanting this is that we are trying to tune our build
and
>> measure our success by looking at the time each build step takes.
>>
>> My understanding is that maven uses log4j/commons-logging, both of
which
>> I'm
>> familiar with.  I then tried to plug a custom log4j.properties into
the
>> right location on the classpath to achieve what I wanted.  I tried
>> setting
>> the following on both command-line and by altering MAVEN_OPTS in
mvn.bat:
>>
>> -Dlog4j.debug=true -Dlog4j.configuration=file:/c:/log4j.properties
>>
>> Neither approach has any effect--I get no log4j debug information,
and my
>> properties file is ignored.  I also tried putting the
log4j.properties in
>> the current directory of the build--this doesn't work either.
Nothing I
>> did
>> seemed able to trigger log4j debug info, making me suspicious as to
>> whether
>> log4j was even in use.
>>
>> I took a quick glance at the maven source code, but was unsuccessful
in
>> locating the logging module to try and trace how the log
configuration is
>> initialized.
>>
>> Anybody know how to customize the "layout" of the maven console
output?
>> Thanks in advance for any pointers.
>>
>> --Ryan
>>
>> P.S. Just to avoid any off-topic responses, note that my junit test
>> output
>> is correctly using a custom log4j.properties (from test/resources,
etc.).
>> However, this is not my objective--I'm trying to customize all maven
>> console
>> output.
>>
>>
>> --
>> View this message in context:
>>
http://www.nabble.com/getting-timestamps-in-console-logging-output-tp160
48940s177p16048940.html
>> Sent from the Maven - Users mailing list archive at Nabble.com.
>>
>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: users-unsubscribe@maven.apache.org
>> For additional commands, e-mail: users-help@maven.apache.org
>>
>>
> 
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@maven.apache.org
> For additional commands, e-mail: users-help@maven.apache.org
> 
> 
> 

-- 
View this message in context:
http://www.nabble.com/getting-timestamps-in-console-logging-output-tp160
48940s177p16060333.html
Sent from the Maven - Users mailing list archive at Nabble.com.


---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@maven.apache.org
For additional commands, e-mail: users-help@maven.apache.org


---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@maven.apache.org
For additional commands, e-mail: users-help@maven.apache.org


Re: getting timestamps in console logging output

Posted by e7a7b7 <ry...@oracle.com>.
Thanks for your response, although I wonder if anybody else has any
additional suggestions?

As per the reason for wanting to time build steps, some background: our
build system is actually a very mature, highly-modularized maven system.  We
use an internal remote repository and have a continuous integration system
running that is continually updating the repository.

Modularity in some ways actually contributes to the performance issues we
are having, since we build a large number of GWT war artifacts with the
gwt-maven-plugin.  For those unfamilar, the GWT-maven-plugin generates a
complete webapp from java code.  The GWT compilation is relatively slow and
not highly configurable.  The wars created are "correct" but somewhat large. 
Shuttling large war files back and forth to the internal repository with
each local build and performing large war overlay operations can be very
slow, and we've tried a number of different techniques to lower the I/O
requirements, including using custom ant steps to pare down the size of the
war artifacts.

Anyway, we are trying to further tune 1) the gwt-maven-plugin and 2) the war
creation/overlay steps to get the maximum performance out of the build. 
Since these steps are somewhat related, it's difficult to measure the impact
of changes without having time stats on each output line.

If anybody has any further suggestions, or can explain anything about how
maven loads its logging configuration, they would be appreciated.  Thanks
again.

--Ryan


Wayne Fay wrote:
> 
> Without knowing for sure but basing my answer on my own reading and
> research into customizing things like this in Maven2, I believe the
> answer is "this is not possible with 2.0.x".
> 
> How long is your build such that this is even an issue? You should
> break things up into small modules so they all build quickly -- then
> you can time those individual module builds and monitor their times
> etc if you really must. If you have a huge monolithic build that takes
> forever, you're probably doing things wrong.
> 
> Wayne
> 
> On 3/14/08, e7a7b7 <ry...@oracle.com> wrote:
>>
>> Hello all,
>>
>> Thanks for hosting a great forum.  I have scoured this forum for the
>> answer
>> to this question, and while there seem to be many logging- and
>> log4j-related
>> questions and answers, I have been unable to figure out how to do what
>> I'm
>> trying to do, which is to add timestamps to the maven console output.
>>
>> For example, I want this:
>> [INFO]
>> ------------------------------------------------------------------------
>> [INFO] BUILD SUCCESSFUL
>> [INFO]
>> ------------------------------------------------------------------------
>>
>> to look instead like this:
>> [2008-03-14 11:20:03,312 INFO]
>> ------------------------------------------------------------------------
>> [2008-03-14 11:20:03,312 INFO] BUILD SUCCESSFUL
>> [2008-03-14 11:20:03,312 INFO]
>> ------------------------------------------------------------------------
>>
>> The reason for wanting this is that we are trying to tune our build and
>> measure our success by looking at the time each build step takes.
>>
>> My understanding is that maven uses log4j/commons-logging, both of which
>> I'm
>> familiar with.  I then tried to plug a custom log4j.properties into the
>> right location on the classpath to achieve what I wanted.  I tried
>> setting
>> the following on both command-line and by altering MAVEN_OPTS in mvn.bat:
>>
>> -Dlog4j.debug=true -Dlog4j.configuration=file:/c:/log4j.properties
>>
>> Neither approach has any effect--I get no log4j debug information, and my
>> properties file is ignored.  I also tried putting the log4j.properties in
>> the current directory of the build--this doesn't work either.  Nothing I
>> did
>> seemed able to trigger log4j debug info, making me suspicious as to
>> whether
>> log4j was even in use.
>>
>> I took a quick glance at the maven source code, but was unsuccessful in
>> locating the logging module to try and trace how the log configuration is
>> initialized.
>>
>> Anybody know how to customize the "layout" of the maven console output?
>> Thanks in advance for any pointers.
>>
>> --Ryan
>>
>> P.S. Just to avoid any off-topic responses, note that my junit test
>> output
>> is correctly using a custom log4j.properties (from test/resources, etc.).
>> However, this is not my objective--I'm trying to customize all maven
>> console
>> output.
>>
>>
>> --
>> View this message in context:
>> http://www.nabble.com/getting-timestamps-in-console-logging-output-tp16048940s177p16048940.html
>> Sent from the Maven - Users mailing list archive at Nabble.com.
>>
>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: users-unsubscribe@maven.apache.org
>> For additional commands, e-mail: users-help@maven.apache.org
>>
>>
> 
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@maven.apache.org
> For additional commands, e-mail: users-help@maven.apache.org
> 
> 
> 

-- 
View this message in context: http://www.nabble.com/getting-timestamps-in-console-logging-output-tp16048940s177p16060333.html
Sent from the Maven - Users mailing list archive at Nabble.com.


---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@maven.apache.org
For additional commands, e-mail: users-help@maven.apache.org


Re: getting timestamps in console logging output

Posted by Wayne Fay <wa...@gmail.com>.
Without knowing for sure but basing my answer on my own reading and
research into customizing things like this in Maven2, I believe the
answer is "this is not possible with 2.0.x".

How long is your build such that this is even an issue? You should
break things up into small modules so they all build quickly -- then
you can time those individual module builds and monitor their times
etc if you really must. If you have a huge monolithic build that takes
forever, you're probably doing things wrong.

Wayne

On 3/14/08, e7a7b7 <ry...@oracle.com> wrote:
>
> Hello all,
>
> Thanks for hosting a great forum.  I have scoured this forum for the answer
> to this question, and while there seem to be many logging- and log4j-related
> questions and answers, I have been unable to figure out how to do what I'm
> trying to do, which is to add timestamps to the maven console output.
>
> For example, I want this:
> [INFO]
> ------------------------------------------------------------------------
> [INFO] BUILD SUCCESSFUL
> [INFO]
> ------------------------------------------------------------------------
>
> to look instead like this:
> [2008-03-14 11:20:03,312 INFO]
> ------------------------------------------------------------------------
> [2008-03-14 11:20:03,312 INFO] BUILD SUCCESSFUL
> [2008-03-14 11:20:03,312 INFO]
> ------------------------------------------------------------------------
>
> The reason for wanting this is that we are trying to tune our build and
> measure our success by looking at the time each build step takes.
>
> My understanding is that maven uses log4j/commons-logging, both of which I'm
> familiar with.  I then tried to plug a custom log4j.properties into the
> right location on the classpath to achieve what I wanted.  I tried setting
> the following on both command-line and by altering MAVEN_OPTS in mvn.bat:
>
> -Dlog4j.debug=true -Dlog4j.configuration=file:/c:/log4j.properties
>
> Neither approach has any effect--I get no log4j debug information, and my
> properties file is ignored.  I also tried putting the log4j.properties in
> the current directory of the build--this doesn't work either.  Nothing I did
> seemed able to trigger log4j debug info, making me suspicious as to whether
> log4j was even in use.
>
> I took a quick glance at the maven source code, but was unsuccessful in
> locating the logging module to try and trace how the log configuration is
> initialized.
>
> Anybody know how to customize the "layout" of the maven console output?
> Thanks in advance for any pointers.
>
> --Ryan
>
> P.S. Just to avoid any off-topic responses, note that my junit test output
> is correctly using a custom log4j.properties (from test/resources, etc.).
> However, this is not my objective--I'm trying to customize all maven console
> output.
>
>
> --
> View this message in context: http://www.nabble.com/getting-timestamps-in-console-logging-output-tp16048940s177p16048940.html
> Sent from the Maven - Users mailing list archive at Nabble.com.
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@maven.apache.org
> For additional commands, e-mail: users-help@maven.apache.org
>
>

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@maven.apache.org
For additional commands, e-mail: users-help@maven.apache.org