You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@groovy.apache.org by Raviteja Lokineni <ra...@gmail.com> on 2016/08/22 20:00:17 UTC
Reporting groovy line number in log4j2
Hi all,
Log4j ouputs groovy class line number to be -1. Any known fix/workaround
for this issue? I looked around a bit but found nothing. FYI, Grails team
doesn't seem to have this issue.
Log4j patern: %d{yyyy-MM-dd HH:mm:ss.SSS(XXX)} [%t] %p %c:%L - %m%n
Sample output I get:
<time> [<thread>] <LEVEL> <class>:*-1* - <message>
Thanks,
--
*Raviteja Lokineni* | Business Intelligence Developer
TD Ameritrade
E: raviteja.lokineni@gmail.com
[image: View Raviteja Lokineni's profile on LinkedIn]
<http://in.linkedin.com/in/ravitejalokineni>
Re: Reporting groovy line number in log4j2
Posted by Maarten Boekhold <bo...@gmx.com>.
Logback added some special support for groovy a long time back for exactly
this reason.
Maarten
On 30 August 2016 3:48:59 p.m. Paul King <pa...@asert.com.au> wrote:
> I had a quick look at log4j. The line number information is extracted by
> walking the stacktrace with a fairly simplistic algorithm. It walks the
> stacktrace and stops one after classes that it expects from the logging
> framework itself. This is true for statically-compiled Groovy but dynamic
> Groovy has numerous additional Groovy runtime entries in the stacktrace.
>
> Here is some self-contained code which illustrates the issue:
>
> @Grab('log4j:log4j:1.2.17')
> import groovy.util.logging.Log4j
>
> @Log4j
> class Foo {
> static main(args) {
> org.apache.log4j.PropertyConfigurator.configure([
> 'log4j.rootLogger': 'INFO,stdout',
> 'log4j.appender.stdout': 'org.apache.log4j.ConsoleAppender',
> 'log4j.appender.stdout.Target': 'System.out',
> 'log4j.appender.stdout.layout': 'org.apache.log4j.PatternLayout',
> 'log4j.appender.stdout.layout.ConversionPattern': '%5p %c{1}:%L -
> %m%n'
> ] as Properties)
> log.info('hello from main') // line 14
> test()
> println 'Line number is:' + new org.apache.log4j.spi.LocationInfo(new
> RuntimeException(),
> 'org.codehaus.groovy.runtime.callsite.AbstractCallSite').lineNumber
> // starts on line 16
>
> }
> @groovy.transform.CompileStatic
> static test() {
> log.info('hello from test') // line 22
>
> }
> }
>
> The output is:
>
> INFO Foo:? - hello from main
> INFO Foo:22 - hello from test
> Line number is:16
>
> The last line of output illustrates that you can get the correct info out
> of the log4j classes if you tell it about the Groovy runtime classes to
> expect in the stacktrace. So, if you really wanted to, you could write your
> own Groovy-aware layout classes. I imagine the story is similar for other
> logging frameworks.
>
> Cheers, Paul.
>
>
>
> On Thu, Aug 25, 2016 at 5:26 AM, Raviteja Lokineni <
> raviteja.lokineni@gmail.com> wrote:
>
>> Just a question out of the blue.
>>
>> Exceptions reported in Groovy seems to report the correct line number,
>> what's wrong with line number logger uses?
>>
>> On Wed, Aug 24, 2016 at 2:36 PM, Raviteja Lokineni <
>> raviteja.lokineni@gmail.com> wrote:
>>
>>> I have added logging(log4j2) in a groovy class which has the following
>>> pseudo code:
>>>
>>> This returns line number -1:
>>> GParsPool.withPool {
>>> <collection>.eachParallel {
>>> //do something
>>> log.debug("<message>")
>>> }
>>> }
>>>
>>> The following also returns -1, although this doesn't seem to be in any
>>> closure:
>>> private void doProcess(<params>) {
>>> log.debug("<message>")
>>> }
>>>
>>> I take my word on grails back. It also returns -1 for line number.
>>> Grails Example:
>>>
>>> package com.sample
>>>
>>> class SampleController {
>>>
>>> def index() {
>>> log.error("test")
>>> render "test"
>>> }
>>> }
>>>
>>>
>>> ERROR grails.app.controllers.com.sample.SampleController
>>> g.a.c.com.sample.SampleController.call(-1) - test
>>>
>>> Thanks,
>>> Raviteja
>>>
>>> On Mon, Aug 22, 2016 at 4:40 PM, Paul King <pa...@asert.com.au> wrote:
>>>
>>>> We set the line number to -1 for generated code which doesn't have a
>>>> corresponding real line in the source code.
>>>>
>>>> So, you might be seeing exactly what we expect or it's possible we have
>>>> missed some case. Can you elaborate further on how you are using the
>>>> logging?
>>>>
>>>> Cheers, Paul.
>>>>
>>>> On Tue, Aug 23, 2016 at 6:00 AM, Raviteja Lokineni <
>>>> raviteja.lokineni@gmail.com> wrote:
>>>>
>>>>> Hi all,
>>>>>
>>>>> Log4j ouputs groovy class line number to be -1. Any known
>>>>> fix/workaround for this issue? I looked around a bit but found nothing.
>>>>> FYI, Grails team doesn't seem to have this issue.
>>>>>
>>>>> Log4j patern: %d{yyyy-MM-dd HH:mm:ss.SSS(XXX)} [%t] %p %c:%L - %m%n
>>>>>
>>>>> Sample output I get:
>>>>> <time> [<thread>] <LEVEL> <class>:*-1* - <message>
>>>>>
>>>>> Thanks,
>>>>> --
>>>>> *Raviteja Lokineni* | Business Intelligence Developer
>>>>> TD Ameritrade
>>>>>
>>>>> E: raviteja.lokineni@gmail.com
>>>>>
>>>>> [image: View Raviteja Lokineni's profile on LinkedIn]
>>>>> <http://in.linkedin.com/in/ravitejalokineni>
>>>>>
>>>>>
>>>>
>>>
>>>
>>> --
>>> *Raviteja Lokineni* | Business Intelligence Developer
>>> TD Ameritrade
>>>
>>> E: raviteja.lokineni@gmail.com
>>>
>>> [image: View Raviteja Lokineni's profile on LinkedIn]
>>> <http://in.linkedin.com/in/ravitejalokineni>
>>>
>>>
>>
>>
>> --
>> *Raviteja Lokineni* | Business Intelligence Developer
>> TD Ameritrade
>>
>> E: raviteja.lokineni@gmail.com
>>
>> [image: View Raviteja Lokineni's profile on LinkedIn]
>> <http://in.linkedin.com/in/ravitejalokineni>
>>
>>
Re: Reporting groovy line number in log4j2
Posted by Paul King <pa...@asert.com.au>.
I had a quick look at log4j. The line number information is extracted by
walking the stacktrace with a fairly simplistic algorithm. It walks the
stacktrace and stops one after classes that it expects from the logging
framework itself. This is true for statically-compiled Groovy but dynamic
Groovy has numerous additional Groovy runtime entries in the stacktrace.
Here is some self-contained code which illustrates the issue:
@Grab('log4j:log4j:1.2.17')
import groovy.util.logging.Log4j
@Log4j
class Foo {
static main(args) {
org.apache.log4j.PropertyConfigurator.configure([
'log4j.rootLogger': 'INFO,stdout',
'log4j.appender.stdout': 'org.apache.log4j.ConsoleAppender',
'log4j.appender.stdout.Target': 'System.out',
'log4j.appender.stdout.layout': 'org.apache.log4j.PatternLayout',
'log4j.appender.stdout.layout.ConversionPattern': '%5p %c{1}:%L -
%m%n'
] as Properties)
log.info('hello from main') // line 14
test()
println 'Line number is:' + new org.apache.log4j.spi.LocationInfo(new
RuntimeException(),
'org.codehaus.groovy.runtime.callsite.AbstractCallSite').lineNumber
// starts on line 16
}
@groovy.transform.CompileStatic
static test() {
log.info('hello from test') // line 22
}
}
The output is:
INFO Foo:? - hello from main
INFO Foo:22 - hello from test
Line number is:16
The last line of output illustrates that you can get the correct info out
of the log4j classes if you tell it about the Groovy runtime classes to
expect in the stacktrace. So, if you really wanted to, you could write your
own Groovy-aware layout classes. I imagine the story is similar for other
logging frameworks.
Cheers, Paul.
On Thu, Aug 25, 2016 at 5:26 AM, Raviteja Lokineni <
raviteja.lokineni@gmail.com> wrote:
> Just a question out of the blue.
>
> Exceptions reported in Groovy seems to report the correct line number,
> what's wrong with line number logger uses?
>
> On Wed, Aug 24, 2016 at 2:36 PM, Raviteja Lokineni <
> raviteja.lokineni@gmail.com> wrote:
>
>> I have added logging(log4j2) in a groovy class which has the following
>> pseudo code:
>>
>> This returns line number -1:
>> GParsPool.withPool {
>> <collection>.eachParallel {
>> //do something
>> log.debug("<message>")
>> }
>> }
>>
>> The following also returns -1, although this doesn't seem to be in any
>> closure:
>> private void doProcess(<params>) {
>> log.debug("<message>")
>> }
>>
>> I take my word on grails back. It also returns -1 for line number.
>> Grails Example:
>>
>> package com.sample
>>
>> class SampleController {
>>
>> def index() {
>> log.error("test")
>> render "test"
>> }
>> }
>>
>>
>> ERROR grails.app.controllers.com.sample.SampleController
>> g.a.c.com.sample.SampleController.call(-1) - test
>>
>> Thanks,
>> Raviteja
>>
>> On Mon, Aug 22, 2016 at 4:40 PM, Paul King <pa...@asert.com.au> wrote:
>>
>>> We set the line number to -1 for generated code which doesn't have a
>>> corresponding real line in the source code.
>>>
>>> So, you might be seeing exactly what we expect or it's possible we have
>>> missed some case. Can you elaborate further on how you are using the
>>> logging?
>>>
>>> Cheers, Paul.
>>>
>>> On Tue, Aug 23, 2016 at 6:00 AM, Raviteja Lokineni <
>>> raviteja.lokineni@gmail.com> wrote:
>>>
>>>> Hi all,
>>>>
>>>> Log4j ouputs groovy class line number to be -1. Any known
>>>> fix/workaround for this issue? I looked around a bit but found nothing.
>>>> FYI, Grails team doesn't seem to have this issue.
>>>>
>>>> Log4j patern: %d{yyyy-MM-dd HH:mm:ss.SSS(XXX)} [%t] %p %c:%L - %m%n
>>>>
>>>> Sample output I get:
>>>> <time> [<thread>] <LEVEL> <class>:*-1* - <message>
>>>>
>>>> Thanks,
>>>> --
>>>> *Raviteja Lokineni* | Business Intelligence Developer
>>>> TD Ameritrade
>>>>
>>>> E: raviteja.lokineni@gmail.com
>>>>
>>>> [image: View Raviteja Lokineni's profile on LinkedIn]
>>>> <http://in.linkedin.com/in/ravitejalokineni>
>>>>
>>>>
>>>
>>
>>
>> --
>> *Raviteja Lokineni* | Business Intelligence Developer
>> TD Ameritrade
>>
>> E: raviteja.lokineni@gmail.com
>>
>> [image: View Raviteja Lokineni's profile on LinkedIn]
>> <http://in.linkedin.com/in/ravitejalokineni>
>>
>>
>
>
> --
> *Raviteja Lokineni* | Business Intelligence Developer
> TD Ameritrade
>
> E: raviteja.lokineni@gmail.com
>
> [image: View Raviteja Lokineni's profile on LinkedIn]
> <http://in.linkedin.com/in/ravitejalokineni>
>
>
Re: Reporting groovy line number in log4j2
Posted by Raviteja Lokineni <ra...@gmail.com>.
Just a question out of the blue.
Exceptions reported in Groovy seems to report the correct line number,
what's wrong with line number logger uses?
On Wed, Aug 24, 2016 at 2:36 PM, Raviteja Lokineni <
raviteja.lokineni@gmail.com> wrote:
> I have added logging(log4j2) in a groovy class which has the following
> pseudo code:
>
> This returns line number -1:
> GParsPool.withPool {
> <collection>.eachParallel {
> //do something
> log.debug("<message>")
> }
> }
>
> The following also returns -1, although this doesn't seem to be in any
> closure:
> private void doProcess(<params>) {
> log.debug("<message>")
> }
>
> I take my word on grails back. It also returns -1 for line number.
> Grails Example:
>
> package com.sample
>
> class SampleController {
>
> def index() {
> log.error("test")
> render "test"
> }
> }
>
>
> ERROR grails.app.controllers.com.sample.SampleController
> g.a.c.com.sample.SampleController.call(-1) - test
>
> Thanks,
> Raviteja
>
> On Mon, Aug 22, 2016 at 4:40 PM, Paul King <pa...@asert.com.au> wrote:
>
>> We set the line number to -1 for generated code which doesn't have a
>> corresponding real line in the source code.
>>
>> So, you might be seeing exactly what we expect or it's possible we have
>> missed some case. Can you elaborate further on how you are using the
>> logging?
>>
>> Cheers, Paul.
>>
>> On Tue, Aug 23, 2016 at 6:00 AM, Raviteja Lokineni <
>> raviteja.lokineni@gmail.com> wrote:
>>
>>> Hi all,
>>>
>>> Log4j ouputs groovy class line number to be -1. Any known fix/workaround
>>> for this issue? I looked around a bit but found nothing. FYI, Grails team
>>> doesn't seem to have this issue.
>>>
>>> Log4j patern: %d{yyyy-MM-dd HH:mm:ss.SSS(XXX)} [%t] %p %c:%L - %m%n
>>>
>>> Sample output I get:
>>> <time> [<thread>] <LEVEL> <class>:*-1* - <message>
>>>
>>> Thanks,
>>> --
>>> *Raviteja Lokineni* | Business Intelligence Developer
>>> TD Ameritrade
>>>
>>> E: raviteja.lokineni@gmail.com
>>>
>>> [image: View Raviteja Lokineni's profile on LinkedIn]
>>> <http://in.linkedin.com/in/ravitejalokineni>
>>>
>>>
>>
>
>
> --
> *Raviteja Lokineni* | Business Intelligence Developer
> TD Ameritrade
>
> E: raviteja.lokineni@gmail.com
>
> [image: View Raviteja Lokineni's profile on LinkedIn]
> <http://in.linkedin.com/in/ravitejalokineni>
>
>
--
*Raviteja Lokineni* | Business Intelligence Developer
TD Ameritrade
E: raviteja.lokineni@gmail.com
[image: View Raviteja Lokineni's profile on LinkedIn]
<http://in.linkedin.com/in/ravitejalokineni>
Re: Reporting groovy line number in log4j2
Posted by Raviteja Lokineni <ra...@gmail.com>.
I have added logging(log4j2) in a groovy class which has the following
pseudo code:
This returns line number -1:
GParsPool.withPool {
<collection>.eachParallel {
//do something
log.debug("<message>")
}
}
The following also returns -1, although this doesn't seem to be in any
closure:
private void doProcess(<params>) {
log.debug("<message>")
}
I take my word on grails back. It also returns -1 for line number.
Grails Example:
package com.sample
class SampleController {
def index() {
log.error("test")
render "test"
}
}
ERROR grails.app.controllers.com.sample.SampleController
g.a.c.com.sample.SampleController.call(-1)
- test
Thanks,
Raviteja
On Mon, Aug 22, 2016 at 4:40 PM, Paul King <pa...@asert.com.au> wrote:
> We set the line number to -1 for generated code which doesn't have a
> corresponding real line in the source code.
>
> So, you might be seeing exactly what we expect or it's possible we have
> missed some case. Can you elaborate further on how you are using the
> logging?
>
> Cheers, Paul.
>
> On Tue, Aug 23, 2016 at 6:00 AM, Raviteja Lokineni <
> raviteja.lokineni@gmail.com> wrote:
>
>> Hi all,
>>
>> Log4j ouputs groovy class line number to be -1. Any known fix/workaround
>> for this issue? I looked around a bit but found nothing. FYI, Grails team
>> doesn't seem to have this issue.
>>
>> Log4j patern: %d{yyyy-MM-dd HH:mm:ss.SSS(XXX)} [%t] %p %c:%L - %m%n
>>
>> Sample output I get:
>> <time> [<thread>] <LEVEL> <class>:*-1* - <message>
>>
>> Thanks,
>> --
>> *Raviteja Lokineni* | Business Intelligence Developer
>> TD Ameritrade
>>
>> E: raviteja.lokineni@gmail.com
>>
>> [image: View Raviteja Lokineni's profile on LinkedIn]
>> <http://in.linkedin.com/in/ravitejalokineni>
>>
>>
>
--
*Raviteja Lokineni* | Business Intelligence Developer
TD Ameritrade
E: raviteja.lokineni@gmail.com
[image: View Raviteja Lokineni's profile on LinkedIn]
<http://in.linkedin.com/in/ravitejalokineni>
Re: Reporting groovy line number in log4j2
Posted by Paul King <pa...@asert.com.au>.
We set the line number to -1 for generated code which doesn't have a
corresponding real line in the source code.
So, you might be seeing exactly what we expect or it's possible we have
missed some case. Can you elaborate further on how you are using the
logging?
Cheers, Paul.
On Tue, Aug 23, 2016 at 6:00 AM, Raviteja Lokineni <
raviteja.lokineni@gmail.com> wrote:
> Hi all,
>
> Log4j ouputs groovy class line number to be -1. Any known fix/workaround
> for this issue? I looked around a bit but found nothing. FYI, Grails team
> doesn't seem to have this issue.
>
> Log4j patern: %d{yyyy-MM-dd HH:mm:ss.SSS(XXX)} [%t] %p %c:%L - %m%n
>
> Sample output I get:
> <time> [<thread>] <LEVEL> <class>:*-1* - <message>
>
> Thanks,
> --
> *Raviteja Lokineni* | Business Intelligence Developer
> TD Ameritrade
>
> E: raviteja.lokineni@gmail.com
>
> [image: View Raviteja Lokineni's profile on LinkedIn]
> <http://in.linkedin.com/in/ravitejalokineni>
>
>