Separate logging for JPMS module/layer

classic Classic list List threaded Threaded
30 messages Options
12
Reply | Threaded
Open this post in threaded view
|

Separate logging for JPMS module/layer

Alex Sviridov
Hi all,

Could anyone say how the following problem can be solved. I want to create separate
log file for every JPMS module/layer. The problem is that many libraries/programs
use LoggerFactory.getLogger(String className) so in getLogger I have only
the name of the class as String, so I can't get module and layer.

If I had not String className, but Class klass then the problem would be easily solved.
As I understand I can't load class by name because it would require all modules export
their packages to logging framework that has no sense.

Are there any solutions for such problem?


--
Alex Sviridov
Reply | Threaded
Open this post in threaded view
|

Re: Separate logging for JPMS module/layer

Remi Forax
You can use the StackWalker
https://docs.oracle.com/en/java/javase/11/docs/api/java.base/java/lang/StackWalker.html

regards,
Rémi

----- Mail original -----
> De: "Alex Sviridov" <[hidden email]>
> À: "jigsaw-dev" <[hidden email]>
> Envoyé: Mardi 2 Octobre 2018 23:54:48
> Objet: Separate logging for JPMS module/layer

> Hi all,
>
> Could anyone say how the following problem can be solved. I want to create
> separate
> log file for every JPMS module/layer. The problem is that many
> libraries/programs
> use LoggerFactory.getLogger(String className) so in getLogger I have only
> the name of the class as String, so I can't get module and layer.
>
> If I had not String className, but Class klass then the problem would be easily
> solved.
> As I understand I can't load class by name because it would require all modules
> export
> their packages to logging framework that has no sense.
>
> Are there any solutions for such problem?
>
>
> --
> Alex Sviridov
Reply | Threaded
Open this post in threaded view
|

Re[2]: Separate logging for JPMS module/layer

Alex Sviridov
Thank you for you suggestion. But can this be used when some library
uses one logging system and for another uses some bridge. Because of this bridging
LoggerFactory.getLogger is called somewhere in bridge, as I understand,


>Среда,  3 октября 2018, 1:12 +03:00 от Remi Forax <[hidden email]>:
>
>You can use the StackWalker
>https://docs.oracle.com/en/java/javase/11/docs/api/java.base/java/lang/StackWalker.html
>
>regards,
>Rémi
>
>----- Mail original -----
>> De: "Alex Sviridov" < [hidden email] >
>> À: "jigsaw-dev" < [hidden email] >
>> Envoyé: Mardi 2 Octobre 2018 23:54:48
>> Objet: Separate logging for JPMS module/layer
>
>> Hi all,
>>
>> Could anyone say how the following problem can be solved. I want to create
>> separate
>> log file for every JPMS module/layer. The problem is that many
>> libraries/programs
>> use LoggerFactory.getLogger(String className) so in getLogger I have only
>> the name of the class as String, so I can't get module and layer.
>>
>> If I had not String className, but Class klass then the problem would be easily
>> solved.
>> As I understand I can't load class by name because it would require all modules
>> export
>> their packages to logging framework that has no sense.
>>
>> Are there any solutions for such problem?
>>
>>
>> --
>> Alex Sviridov


--
Alex Sviridov
Reply | Threaded
Open this post in threaded view
|

Re: Re[2]: Separate logging for JPMS module/layer

Remi Forax
> De: "Alex Sviridov" <[hidden email]>
> À: "Remi Forax" <[hidden email]>, "jigsaw-dev" <[hidden email]>
> Envoyé: Mercredi 3 Octobre 2018 00:20:08
> Objet: Re[2]: Separate logging for JPMS module/layer

> Thank you for you suggestion. But can this be used when some library
> uses one logging system and for another uses some bridge. Because of this
> bridging
> LoggerFactory.getLogger is called somewhere in bridge, as I understand,
You can still skip over the method of the bridge, but usually it only works if you know all the bridges that can happen because this code tend to be depend on the implementation of each bridge,
practically, there is less than half a dozen of logging libraries used in Java, so it's doable.

The other solution is to ask every maintainers of the logging libraries to implement the System.Logger API introduced in 9.

Rémi

>> Среда, 3 октября 2018, 1:12 +03:00 от Remi Forax <[hidden email]>:

>> You can use the StackWalker
>> [
>> https://docs.oracle.com/en/java/javase/11/docs/api/java.base/java/lang/StackWalker.html
>> |
>> https://docs.oracle.com/en/java/javase/11/docs/api/java.base/java/lang/StackWalker.html
>> ]

>> regards,
>> Rémi

>> ----- Mail original -----
>> > De: "Alex Sviridov" < [ mailto:[hidden email] | [hidden email] ] >
>>> À: "jigsaw-dev" < [ mailto:[hidden email] |
>> > [hidden email] ] >
>> > Envoyé: Mardi 2 Octobre 2018 23:54:48
>> > Objet: Separate logging for JPMS module/layer

>> > Hi all,

>> > Could anyone say how the following problem can be solved. I want to create
>> > separate
>> > log file for every JPMS module/layer. The problem is that many
>> > libraries/programs
>> > use LoggerFactory.getLogger(String className) so in getLogger I have only
>> > the name of the class as String, so I can't get module and layer.

>> > If I had not String className, but Class klass then the problem would be easily
>> > solved.
>> > As I understand I can't load class by name because it would require all modules
>> > export
>> > their packages to logging framework that has no sense.

>> > Are there any solutions for such problem?


>> > --
>> > Alex Sviridov

> --
> Alex Sviridov
Reply | Threaded
Open this post in threaded view
|

Re[4]: Separate logging for JPMS module/layer

Alex Sviridov
However, if code must depend on implementation is is a not good way - it is not robust,
it is hard to update. Seems there is no chance to make a good universal logger per module/layer as
we cannot get the Module/ModuleLayer of the class having only String className.


>Среда,  3 октября 2018, 1:37 +03:00 от [hidden email]:
>
>
>
>----------------------------------------------------------------------
>>De:  "Alex Sviridov" < [hidden email] >
>>À:  "Remi Forax" < [hidden email] >, "jigsaw-dev" < [hidden email] >
>>Envoyé:  Mercredi 3 Octobre 2018 00:20:08
>>Objet:  Re[2]: Separate logging for JPMS module/layer
>>Thank you for you suggestion. But can this be used when some library
>>uses one logging system and for another uses some bridge. Because of this bridging
>>LoggerFactory.getLogger is called somewhere in bridge, as I understand,
>
>You can still skip over the method of the bridge, but usually it only works if you know all the bridges that can happen because this code tend to be depend on the implementation of each bridge,
>practically, there is less than half a dozen of logging libraries used in Java, so it's doable.
>
>The other solution is to ask every maintainers of the logging libraries to implement the System.Logger API introduced in 9.

>Rémi
>>
>>
>>
>>>Среда,  3 октября 2018, 1:12 +03:00 от Remi Forax < [hidden email] >:
>>>
>>>You can use the StackWalker
>>>https://docs.oracle.com/en/java/javase/11/docs/api/java.base/java/lang/StackWalker.html
>>>
>>>regards,
>>>Rémi
>>>
>>>----- Mail original -----
>>>> De: "Alex Sviridov" < [hidden email] >
>>>> À: "jigsaw-dev" < [hidden email] >
>>>> Envoyé: Mardi 2 Octobre 2018 23:54:48
>>>> Objet: Separate logging for JPMS module/layer
>>>
>>>> Hi all,
>>>>
>>>> Could anyone say how the following problem can be solved. I want to create
>>>> separate
>>>> log file for every JPMS module/layer. The problem is that many
>>>> libraries/programs
>>>> use LoggerFactory.getLogger(String className) so in getLogger I have only
>>>> the name of the class as String, so I can't get module and layer.
>>>>
>>>> If I had not String className, but Class klass then the problem would be easily
>>>> solved.
>>>> As I understand I can't load class by name because it would require all modules
>>>> export
>>>> their packages to logging framework that has no sense.
>>>>
>>>> Are there any solutions for such problem?
>>>>
>>>>
>>>> --
>>>> Alex Sviridov
>>
>>
>>--
>>Alex Sviridov


--
Alex Sviridov
Reply | Threaded
Open this post in threaded view
|

Re: Separate logging for JPMS module/layer

Ralph Goers
In reply to this post by Alex Sviridov
Log4j handles this by capturing the fully qualified class name of the logging adapter. Obviously, this doesn’t work if the adapter doesn’t pass Log4j the FQCN, but it does work for the adapters we support.  That said, it is very slow to capture this and is probably the biggest pain point. Log4j recommends not capturing this information in production environments because it is so slow. Unfortunately, it seems to have gotten even slower in Java 9+. In an ideal world we would be able to capture the caller information at compile time but Java provides no good way to do this. Wouldn’t it be great if I could just code something like logger.error(_CallerInfo_, “hello”) and the compiler would provide the caller info data structure that was generated by the compiler?

FWIW, I do plan to add the module information to the caller information provided with Log4j but just haven’t gotten to it. You are more than welcome to provide a patch.

Ralph

> On Oct 2, 2018, at 3:20 PM, Alex Sviridov <[hidden email]> wrote:
>
> Thank you for you suggestion. But can this be used when some library
> uses one logging system and for another uses some bridge. Because of this bridging
> LoggerFactory.getLogger is called somewhere in bridge, as I understand,
>
>
>> Среда,  3 октября 2018, 1:12 +03:00 от Remi Forax <[hidden email]>:
>>
>> You can use the StackWalker
>> https://docs.oracle.com/en/java/javase/11/docs/api/java.base/java/lang/StackWalker.html
>>
>> regards,
>> Rémi
>>
>> ----- Mail original -----
>>> De: "Alex Sviridov" < [hidden email] >
>>> À: "jigsaw-dev" < [hidden email] >
>>> Envoyé: Mardi 2 Octobre 2018 23:54:48
>>> Objet: Separate logging for JPMS module/layer
>>
>>> Hi all,
>>>
>>> Could anyone say how the following problem can be solved. I want to create
>>> separate
>>> log file for every JPMS module/layer. The problem is that many
>>> libraries/programs
>>> use LoggerFactory.getLogger(String className) so in getLogger I have only
>>> the name of the class as String, so I can't get module and layer.
>>>
>>> If I had not String className, but Class klass then the problem would be easily
>>> solved.
>>> As I understand I can't load class by name because it would require all modules
>>> export
>>> their packages to logging framework that has no sense.
>>>
>>> Are there any solutions for such problem?
>>>
>>>
>>> --
>>> Alex Sviridov
>
>
> --
> Alex Sviridov


Reply | Threaded
Open this post in threaded view
|

Re[2]: Separate logging for JPMS module/layer

Alex Sviridov
Hi Ralph

I would like to try to implement something if I knew how to solve the following problem. In logger we have
only String someClassStr (fqdn). In order to add to MDC some information about module/layer I need to
get Class someClass, as I know only one way to get information for this class -
someClass.getModule()[.getLayer()]. When I have only someClassStr I don't know how I get information
about module and layer.


>Среда,  3 октября 2018, 19:26 +03:00 от Ralph Goers <[hidden email]>:
>
>Log4j handles this by capturing the fully qualified class name of the logging adapter. Obviously, this doesn’t work if the adapter doesn’t pass Log4j the FQCN, but it does work for the adapters we support.  That said, it is very slow to capture this and is probably the biggest pain point. Log4j recommends not capturing this information in production environments because it is so slow. Unfortunately, it seems to have gotten even slower in Java 9+. In an ideal world we would be able to capture the caller information at compile time but Java provides no good way to do this. Wouldn’t it be great if I could just code something like logger.error(_CallerInfo_, “hello”) and the compiler would provide the caller info data structure that was generated by the compiler?
>
>FWIW, I do plan to add the module information to the caller information provided with Log4j but just haven’t gotten to it. You are more than welcome to provide a patch.
>
>Ralph
>
>> On Oct 2, 2018, at 3:20 PM, Alex Sviridov < [hidden email] > wrote:
>>
>> Thank you for you suggestion. But can this be used when some library
>> uses one logging system and for another uses some bridge. Because of this bridging
>> LoggerFactory.getLogger is called somewhere in bridge, as I understand,
>>
>>
>>> Среда,  3 октября 2018, 1:12 +03:00 от Remi Forax < [hidden email] >:
>>>
>>> You can use the StackWalker
>>>  https://docs.oracle.com/en/java/javase/11/docs/api/java.base/java/lang/StackWalker.html
>>>
>>> regards,
>>> Rémi
>>>
>>> ----- Mail original -----
>>>> De: "Alex Sviridov" <  [hidden email] >
>>>> À: "jigsaw-dev" <  [hidden email] >
>>>> Envoyé: Mardi 2 Octobre 2018 23:54:48
>>>> Objet: Separate logging for JPMS module/layer
>>>
>>>> Hi all,
>>>>
>>>> Could anyone say how the following problem can be solved. I want to create
>>>> separate
>>>> log file for every JPMS module/layer. The problem is that many
>>>> libraries/programs
>>>> use LoggerFactory.getLogger(String className) so in getLogger I have only
>>>> the name of the class as String, so I can't get module and layer.
>>>>
>>>> If I had not String className, but Class klass then the problem would be easily
>>>> solved.
>>>> As I understand I can't load class by name because it would require all modules
>>>> export
>>>> their packages to logging framework that has no sense.
>>>>
>>>> Are there any solutions for such problem?
>>>>
>>>>
>>>> --
>>>> Alex Sviridov
>>
>>
>> --
>> Alex Sviridov
>
>


--
Alex Sviridov
Reply | Threaded
Open this post in threaded view
|

Re: Separate logging for JPMS module/layer

Alan Bateman
In reply to this post by Ralph Goers
On 03/10/2018 17:26, Ralph Goers wrote:
> Log4j handles this by capturing the fully qualified class name of the logging adapter. Obviously, this doesn’t work if the adapter doesn’t pass Log4j the FQCN, but it does work for the adapters we support.  That said, it is very slow to capture this and is probably the biggest pain point. Log4j recommends not capturing this information in production environments because it is so slow. Unfortunately, it seems to have gotten even slower in Java 9+.
Would it be possible to create a small test case to demonstrate the
performance regression that you are seeing? The StackWalker API was
added in Java SE 9 so I can't tell if you are comparing that to
sun.reflect.Reflection::getCallerClass or something else.

-Alan
Reply | Threaded
Open this post in threaded view
|

Re: Separate logging for JPMS module/layer

Ralph Goers
I will take a look and see what tests we have.

Ralph

> On Oct 3, 2018, at 10:38 AM, Alan Bateman <[hidden email]> wrote:
>
> On 03/10/2018 17:26, Ralph Goers wrote:
>> Log4j handles this by capturing the fully qualified class name of the logging adapter. Obviously, this doesn’t work if the adapter doesn’t pass Log4j the FQCN, but it does work for the adapters we support.  That said, it is very slow to capture this and is probably the biggest pain point. Log4j recommends not capturing this information in production environments because it is so slow. Unfortunately, it seems to have gotten even slower in Java 9+.
> Would it be possible to create a small test case to demonstrate the performance regression that you are seeing? The StackWalker API was added in Java SE 9 so I can't tell if you are comparing that to sun.reflect.Reflection::getCallerClass or something else.
>
> -Alan
>


Reply | Threaded
Open this post in threaded view
|

Re: Separate logging for JPMS module/layer

Remi Forax
In reply to this post by Alex Sviridov
I was thinking about capturing the call stack when you create the logger (to get the module), not when you call the logger.

cheers,
Rémi

----- Mail original -----
> De: "Ralph Goers" <[hidden email]>
> À: "Alex Sviridov" <[hidden email]>
> Cc: "Remi Forax" <[hidden email]>, "jigsaw-dev" <[hidden email]>
> Envoyé: Mercredi 3 Octobre 2018 05:08:27
> Objet: Re: Separate logging for JPMS module/layer

> Log4j handles this by capturing the fully qualified class name of the logging
> adapter. Obviously, this doesn’t work if the adapter doesn’t pass Log4j the
> FQCN, but it does work for the adapters we support.  That said, it is very slow
> to capture this and is probably the biggest pain point. Log4j recommends not
> capturing this information in production environments because it is so slow.
> Unfortunately, it seems to have gotten even slower in Java 9+. In an ideal
> world we would be able to capture the caller information at compile time but
> Java provides no good way to do this. Wouldn’t it be great if I could just code
> something like logger.error(_CallerInfo_, “hello”) and the compiler would
> provide the caller info data structure that was generated by the compiler?
>
> FWIW, I do plan to add the module information to the caller information provided
> with Log4j but just haven’t gotten to it. You are more than welcome to provide
> a patch.
>
> Ralph
>
>> On Oct 2, 2018, at 3:20 PM, Alex Sviridov <[hidden email]> wrote:
>>
>> Thank you for you suggestion. But can this be used when some library
>> uses one logging system and for another uses some bridge. Because of this
>> bridging
>> LoggerFactory.getLogger is called somewhere in bridge, as I understand,
>>
>>
>>> Среда,  3 октября 2018, 1:12 +03:00 от Remi Forax <[hidden email]>:
>>>
>>> You can use the StackWalker
>>> https://docs.oracle.com/en/java/javase/11/docs/api/java.base/java/lang/StackWalker.html
>>>
>>> regards,
>>> Rémi
>>>
>>> ----- Mail original -----
>>>> De: "Alex Sviridov" < [hidden email] >
>>>> À: "jigsaw-dev" < [hidden email] >
>>>> Envoyé: Mardi 2 Octobre 2018 23:54:48
>>>> Objet: Separate logging for JPMS module/layer
>>>
>>>> Hi all,
>>>>
>>>> Could anyone say how the following problem can be solved. I want to create
>>>> separate
>>>> log file for every JPMS module/layer. The problem is that many
>>>> libraries/programs
>>>> use LoggerFactory.getLogger(String className) so in getLogger I have only
>>>> the name of the class as String, so I can't get module and layer.
>>>>
>>>> If I had not String className, but Class klass then the problem would be easily
>>>> solved.
>>>> As I understand I can't load class by name because it would require all modules
>>>> export
>>>> their packages to logging framework that has no sense.
>>>>
>>>> Are there any solutions for such problem?
>>>>
>>>>
>>>> --
>>>> Alex Sviridov
>>
>>
>> --
> > Alex Sviridov
Reply | Threaded
Open this post in threaded view
|

Re: Separate logging for JPMS module/layer

Ralph Goers
Hmm, it would probably be a safe assumption that a Logger will never be used outside of the module. That isn’t true of the class name, method name and line number though. I’m not sure how much extra overhead there is in collecting the module name when you have to collect those to.

I should add that when printing exceptions we do cache the file name/location as we are processing the classes for an extended stack trace. We probably will want to add the module name to the extended stack trace as well.

Ralph

> On Oct 4, 2018, at 10:26 AM, [hidden email] wrote:
>
> I was thinking about capturing the call stack when you create the logger (to get the module), not when you call the logger.
>
> cheers,
> Rémi
>
> ----- Mail original -----
>> De: "Ralph Goers" <[hidden email]>
>> À: "Alex Sviridov" <[hidden email]>
>> Cc: "Remi Forax" <[hidden email]>, "jigsaw-dev" <[hidden email]>
>> Envoyé: Mercredi 3 Octobre 2018 05:08:27
>> Objet: Re: Separate logging for JPMS module/layer
>
>> Log4j handles this by capturing the fully qualified class name of the logging
>> adapter. Obviously, this doesn’t work if the adapter doesn’t pass Log4j the
>> FQCN, but it does work for the adapters we support.  That said, it is very slow
>> to capture this and is probably the biggest pain point. Log4j recommends not
>> capturing this information in production environments because it is so slow.
>> Unfortunately, it seems to have gotten even slower in Java 9+. In an ideal
>> world we would be able to capture the caller information at compile time but
>> Java provides no good way to do this. Wouldn’t it be great if I could just code
>> something like logger.error(_CallerInfo_, “hello”) and the compiler would
>> provide the caller info data structure that was generated by the compiler?
>>
>> FWIW, I do plan to add the module information to the caller information provided
>> with Log4j but just haven’t gotten to it. You are more than welcome to provide
>> a patch.
>>
>> Ralph
>>
>>> On Oct 2, 2018, at 3:20 PM, Alex Sviridov <[hidden email]> wrote:
>>>
>>> Thank you for you suggestion. But can this be used when some library
>>> uses one logging system and for another uses some bridge. Because of this
>>> bridging
>>> LoggerFactory.getLogger is called somewhere in bridge, as I understand,
>>>
>>>
>>>> Среда,  3 октября 2018, 1:12 +03:00 от Remi Forax <[hidden email]>:
>>>>
>>>> You can use the StackWalker
>>>> https://docs.oracle.com/en/java/javase/11/docs/api/java.base/java/lang/StackWalker.html
>>>>
>>>> regards,
>>>> Rémi
>>>>
>>>> ----- Mail original -----
>>>>> De: "Alex Sviridov" < [hidden email] >
>>>>> À: "jigsaw-dev" < [hidden email] >
>>>>> Envoyé: Mardi 2 Octobre 2018 23:54:48
>>>>> Objet: Separate logging for JPMS module/layer
>>>>
>>>>> Hi all,
>>>>>
>>>>> Could anyone say how the following problem can be solved. I want to create
>>>>> separate
>>>>> log file for every JPMS module/layer. The problem is that many
>>>>> libraries/programs
>>>>> use LoggerFactory.getLogger(String className) so in getLogger I have only
>>>>> the name of the class as String, so I can't get module and layer.
>>>>>
>>>>> If I had not String className, but Class klass then the problem would be easily
>>>>> solved.
>>>>> As I understand I can't load class by name because it would require all modules
>>>>> export
>>>>> their packages to logging framework that has no sense.
>>>>>
>>>>> Are there any solutions for such problem?
>>>>>
>>>>>
>>>>> --
>>>>> Alex Sviridov
>>>
>>>
>>> --
>>> Alex Sviridov
>


Reply | Threaded
Open this post in threaded view
|

Re: Separate logging for JPMS module/layer

Mandy Chung
If you are looking for the immediate caller, you can try
StackWalker::getCallerClass which only walks the top few
frames and intends to be lower cost.

Mandy

On 10/4/18 2:04 PM, Ralph Goers wrote:

> Hmm, it would probably be a safe assumption that a Logger will never be used outside of the module. That isn’t true of the class name, method name and line number though. I’m not sure how much extra overhead there is in collecting the module name when you have to collect those to.
>
> I should add that when printing exceptions we do cache the file name/location as we are processing the classes for an extended stack trace. We probably will want to add the module name to the extended stack trace as well.
>
> Ralph
>
>> On Oct 4, 2018, at 10:26 AM, [hidden email] wrote:
>>
>> I was thinking about capturing the call stack when you create the logger (to get the module), not when you call the logger.
>>
>> cheers,
>> Rémi
>>
>> ----- Mail original -----
>>> De: "Ralph Goers" <[hidden email]>
>>> À: "Alex Sviridov" <[hidden email]>
>>> Cc: "Remi Forax" <[hidden email]>, "jigsaw-dev" <[hidden email]>
>>> Envoyé: Mercredi 3 Octobre 2018 05:08:27
>>> Objet: Re: Separate logging for JPMS module/layer
>>> Log4j handles this by capturing the fully qualified class name of the logging
>>> adapter. Obviously, this doesn’t work if the adapter doesn’t pass Log4j the
>>> FQCN, but it does work for the adapters we support.  That said, it is very slow
>>> to capture this and is probably the biggest pain point. Log4j recommends not
>>> capturing this information in production environments because it is so slow.
>>> Unfortunately, it seems to have gotten even slower in Java 9+. In an ideal
>>> world we would be able to capture the caller information at compile time but
>>> Java provides no good way to do this. Wouldn’t it be great if I could just code
>>> something like logger.error(_CallerInfo_, “hello”) and the compiler would
>>> provide the caller info data structure that was generated by the compiler?
>>>
>>> FWIW, I do plan to add the module information to the caller information provided
>>> with Log4j but just haven’t gotten to it. You are more than welcome to provide
>>> a patch.
>>>
>>> Ralph
>>>
>>>> On Oct 2, 2018, at 3:20 PM, Alex Sviridov <[hidden email]> wrote:
>>>>
>>>> Thank you for you suggestion. But can this be used when some library
>>>> uses one logging system and for another uses some bridge. Because of this
>>>> bridging
>>>> LoggerFactory.getLogger is called somewhere in bridge, as I understand,
>>>>
>>>>
>>>>> Среда,  3 октября 2018, 1:12 +03:00 от Remi Forax <[hidden email]>:
>>>>>
>>>>> You can use the StackWalker
>>>>> https://docs.oracle.com/en/java/javase/11/docs/api/java.base/java/lang/StackWalker.html
>>>>>
>>>>> regards,
>>>>> Rémi
>>>>>
>>>>> ----- Mail original -----
>>>>>> De: "Alex Sviridov" < [hidden email] >
>>>>>> À: "jigsaw-dev" < [hidden email] >
>>>>>> Envoyé: Mardi 2 Octobre 2018 23:54:48
>>>>>> Objet: Separate logging for JPMS module/layer
>>>>>> Hi all,
>>>>>>
>>>>>> Could anyone say how the following problem can be solved. I want to create
>>>>>> separate
>>>>>> log file for every JPMS module/layer. The problem is that many
>>>>>> libraries/programs
>>>>>> use LoggerFactory.getLogger(String className) so in getLogger I have only
>>>>>> the name of the class as String, so I can't get module and layer.
>>>>>>
>>>>>> If I had not String className, but Class klass then the problem would be easily
>>>>>> solved.
>>>>>> As I understand I can't load class by name because it would require all modules
>>>>>> export
>>>>>> their packages to logging framework that has no sense.
>>>>>>
>>>>>> Are there any solutions for such problem?
>>>>>>
>>>>>>
>>>>>> --
>>>>>> Alex Sviridov
>>>>
>>>> --
>>>> Alex Sviridov
>

Reply | Threaded
Open this post in threaded view
|

Re: Separate logging for JPMS module/layer

Luke Hutchison
If you need to read the stack in a manner that is backwards compatible with
JDK 8 or earlier, there's also the following mechanism for getting the call
stack, by creating a SecurityManager:

https://github.com/classgraph/classgraph/blob/master/src/main/java/io/github/classgraph/utils/CallStackReader.java

However, is there a reason to believe the above mechanism might stop
working in the future?

Under what conditions might SecurityManager not allow
RuntimePermission("createSecurityManager") , and how common is this likely
to be?

Will there be situations where StackWalker will succeed in reading the call
stack but SecurityManager will fail, or vice versa?



On Thu, Oct 4, 2018 at 3:51 PM Mandy Chung <[hidden email]> wrote:

> If you are looking for the immediate caller, you can try
> StackWalker::getCallerClass which only walks the top few
> frames and intends to be lower cost.
>
> Mandy
>
> On 10/4/18 2:04 PM, Ralph Goers wrote:
> > Hmm, it would probably be a safe assumption that a Logger will never be
> used outside of the module. That isn’t true of the class name, method name
> and line number though. I’m not sure how much extra overhead there is in
> collecting the module name when you have to collect those to.
> >
> > I should add that when printing exceptions we do cache the file
> name/location as we are processing the classes for an extended stack trace.
> We probably will want to add the module name to the extended stack trace as
> well.
> >
> > Ralph
> >
> >> On Oct 4, 2018, at 10:26 AM, [hidden email] wrote:
> >>
> >> I was thinking about capturing the call stack when you create the
> logger (to get the module), not when you call the logger.
> >>
> >> cheers,
> >> Rémi
> >>
> >> ----- Mail original -----
> >>> De: "Ralph Goers" <[hidden email]>
> >>> À: "Alex Sviridov" <[hidden email]>
> >>> Cc: "Remi Forax" <[hidden email]>, "jigsaw-dev" <
> [hidden email]>
> >>> Envoyé: Mercredi 3 Octobre 2018 05:08:27
> >>> Objet: Re: Separate logging for JPMS module/layer
> >>> Log4j handles this by capturing the fully qualified class name of the
> logging
> >>> adapter. Obviously, this doesn’t work if the adapter doesn’t pass
> Log4j the
> >>> FQCN, but it does work for the adapters we support.  That said, it is
> very slow
> >>> to capture this and is probably the biggest pain point. Log4j
> recommends not
> >>> capturing this information in production environments because it is so
> slow.
> >>> Unfortunately, it seems to have gotten even slower in Java 9+. In an
> ideal
> >>> world we would be able to capture the caller information at compile
> time but
> >>> Java provides no good way to do this. Wouldn’t it be great if I could
> just code
> >>> something like logger.error(_CallerInfo_, “hello”) and the compiler
> would
> >>> provide the caller info data structure that was generated by the
> compiler?
> >>>
> >>> FWIW, I do plan to add the module information to the caller
> information provided
> >>> with Log4j but just haven’t gotten to it. You are more than welcome to
> provide
> >>> a patch.
> >>>
> >>> Ralph
> >>>
> >>>> On Oct 2, 2018, at 3:20 PM, Alex Sviridov <[hidden email]>
> wrote:
> >>>>
> >>>> Thank you for you suggestion. But can this be used when some library
> >>>> uses one logging system and for another uses some bridge. Because of
> this
> >>>> bridging
> >>>> LoggerFactory.getLogger is called somewhere in bridge, as I
> understand,
> >>>>
> >>>>
> >>>>> Среда,  3 октября 2018, 1:12 +03:00 от Remi Forax <[hidden email]
> >:
> >>>>>
> >>>>> You can use the StackWalker
> >>>>>
> https://docs.oracle.com/en/java/javase/11/docs/api/java.base/java/lang/StackWalker.html
> >>>>>
> >>>>> regards,
> >>>>> Rémi
> >>>>>
> >>>>> ----- Mail original -----
> >>>>>> De: "Alex Sviridov" < [hidden email] >
> >>>>>> À: "jigsaw-dev" < [hidden email] >
> >>>>>> Envoyé: Mardi 2 Octobre 2018 23:54:48
> >>>>>> Objet: Separate logging for JPMS module/layer
> >>>>>> Hi all,
> >>>>>>
> >>>>>> Could anyone say how the following problem can be solved. I want to
> create
> >>>>>> separate
> >>>>>> log file for every JPMS module/layer. The problem is that many
> >>>>>> libraries/programs
> >>>>>> use LoggerFactory.getLogger(String className) so in getLogger I
> have only
> >>>>>> the name of the class as String, so I can't get module and layer.
> >>>>>>
> >>>>>> If I had not String className, but Class klass then the problem
> would be easily
> >>>>>> solved.
> >>>>>> As I understand I can't load class by name because it would require
> all modules
> >>>>>> export
> >>>>>> their packages to logging framework that has no sense.
> >>>>>>
> >>>>>> Are there any solutions for such problem?
> >>>>>>
> >>>>>>
> >>>>>> --
> >>>>>> Alex Sviridov
> >>>>
> >>>> --
> >>>> Alex Sviridov
> >
>
>
Reply | Threaded
Open this post in threaded view
|

Re: Separate logging for JPMS module/layer

Mandy Chung


On 10/4/18 3:08 PM, Luke Hutchison wrote:

> If you need to read the stack in a manner that is backwards compatible
> with JDK 8 or earlier, there's also the following mechanism for
> getting the call stack, by creating a SecurityManager:
>
> https://github.com/classgraph/classgraph/blob/master/src/main/java/io/github/classgraph/utils/CallStackReader.java
>
> However, is there a reason to believe the above mechanism might stop
> working in the future?
>
> Under what conditions might SecurityManager not allow
> RuntimePermission("createSecurityManager") , and how common is this
> likely to be?
>

It depends on whether the security manager is created with a
doPrivileged and whether the permission is granted to the code source
creating the security manager.

> Will there be situations where StackWalker will succeed in reading the
> call stack but SecurityManager will fail, or vice versa?
>

SecurityManager::getClassContext is designed for the security permission
check.  It's not for stack walking.

The stackwalker returns the frames it traverses and if not filtered.  
SM::getClassContext is for permission check and it may filter
unnecessary frames as it wishes (for example native frames as I see).

Mandy

>
>
> On Thu, Oct 4, 2018 at 3:51 PM Mandy Chung <[hidden email]
> <mailto:[hidden email]>> wrote:
>
>     If you are looking for the immediate caller, you can try
>     StackWalker::getCallerClass which only walks the top few
>     frames and intends to be lower cost.
>
>     Mandy
>
>     On 10/4/18 2:04 PM, Ralph Goers wrote:
>     > Hmm, it would probably be a safe assumption that a Logger will
>     never be used outside of the module. That isn’t true of the class
>     name, method name and line number though. I’m not sure how much
>     extra overhead there is in collecting the module name when you
>     have to collect those to.
>     >
>     > I should add that when printing exceptions we do cache the file
>     name/location as we are processing the classes for an extended
>     stack trace. We probably will want to add the module name to the
>     extended stack trace as well.
>     >
>     > Ralph
>     >
>     >> On Oct 4, 2018, at 10:26 AM, [hidden email]
>     <mailto:[hidden email]> wrote:
>     >>
>     >> I was thinking about capturing the call stack when you create
>     the logger (to get the module), not when you call the logger.
>     >>
>     >> cheers,
>     >> Rémi
>     >>
>     >> ----- Mail original -----
>     >>> De: "Ralph Goers" <[hidden email]
>     <mailto:[hidden email]>>
>     >>> À: "Alex Sviridov" <[hidden email]
>     <mailto:[hidden email]>>
>     >>> Cc: "Remi Forax" <[hidden email]
>     <mailto:[hidden email]>>, "jigsaw-dev"
>     <[hidden email] <mailto:[hidden email]>>
>     >>> Envoyé: Mercredi 3 Octobre 2018 05:08:27
>     >>> Objet: Re: Separate logging for JPMS module/layer
>     >>> Log4j handles this by capturing the fully qualified class name
>     of the logging
>     >>> adapter. Obviously, this doesn’t work if the adapter doesn’t
>     pass Log4j the
>     >>> FQCN, but it does work for the adapters we support.  That
>     said, it is very slow
>     >>> to capture this and is probably the biggest pain point. Log4j
>     recommends not
>     >>> capturing this information in production environments because
>     it is so slow.
>     >>> Unfortunately, it seems to have gotten even slower in Java 9+.
>     In an ideal
>     >>> world we would be able to capture the caller information at
>     compile time but
>     >>> Java provides no good way to do this. Wouldn’t it be great if
>     I could just code
>     >>> something like logger.error(_CallerInfo_, “hello”) and the
>     compiler would
>     >>> provide the caller info data structure that was generated by
>     the compiler?
>     >>>
>     >>> FWIW, I do plan to add the module information to the caller
>     information provided
>     >>> with Log4j but just haven’t gotten to it. You are more than
>     welcome to provide
>     >>> a patch.
>     >>>
>     >>> Ralph
>     >>>
>     >>>> On Oct 2, 2018, at 3:20 PM, Alex Sviridov
>     <[hidden email] <mailto:[hidden email]>> wrote:
>     >>>>
>     >>>> Thank you for you suggestion. But can this be used when some
>     library
>     >>>> uses one logging system and for another uses some bridge.
>     Because of this
>     >>>> bridging
>     >>>> LoggerFactory.getLogger is called somewhere in bridge, as I
>     understand,
>     >>>>
>     >>>>
>     >>>>> Среда,  3 октября 2018, 1:12 +03:00 от Remi Forax
>     <[hidden email] <mailto:[hidden email]>>:
>     >>>>>
>     >>>>> You can use the StackWalker
>     >>>>>
>     https://docs.oracle.com/en/java/javase/11/docs/api/java.base/java/lang/StackWalker.html
>     >>>>>
>     >>>>> regards,
>     >>>>> Rémi
>     >>>>>
>     >>>>> ----- Mail original -----
>     >>>>>> De: "Alex Sviridov" < [hidden email]
>     <mailto:[hidden email]> >
>     >>>>>> À: "jigsaw-dev" < [hidden email]
>     <mailto:[hidden email]> >
>     >>>>>> Envoyé: Mardi 2 Octobre 2018 23:54:48
>     >>>>>> Objet: Separate logging for JPMS module/layer
>     >>>>>> Hi all,
>     >>>>>>
>     >>>>>> Could anyone say how the following problem can be solved. I
>     want to create
>     >>>>>> separate
>     >>>>>> log file for every JPMS module/layer. The problem is that many
>     >>>>>> libraries/programs
>     >>>>>> use LoggerFactory.getLogger(String className) so in
>     getLogger I have only
>     >>>>>> the name of the class as String, so I can't get module and
>     layer.
>     >>>>>>
>     >>>>>> If I had not String className, but Class klass then the
>     problem would be easily
>     >>>>>> solved.
>     >>>>>> As I understand I can't load class by name because it would
>     require all modules
>     >>>>>> export
>     >>>>>> their packages to logging framework that has no sense.
>     >>>>>>
>     >>>>>> Are there any solutions for such problem?
>     >>>>>>
>     >>>>>>
>     >>>>>> --
>     >>>>>> Alex Sviridov
>     >>>>
>     >>>> --
>     >>>> Alex Sviridov
>     >
>

Reply | Threaded
Open this post in threaded view
|

Re: Separate logging for JPMS module/layer

Ralph Goers
In reply to this post by Mandy Chung
Unfortunately, we can’t use getCallerClass. Some API methods can be called by users of the API or by other methods in the API class.

Ralph

> On Oct 4, 2018, at 2:50 PM, Mandy Chung <[hidden email]> wrote:
>
> If you are looking for the immediate caller, you can try
> StackWalker::getCallerClass which only walks the top few
> frames and intends to be lower cost.
>
> Mandy
>
> On 10/4/18 2:04 PM, Ralph Goers wrote:
>> Hmm, it would probably be a safe assumption that a Logger will never be used outside of the module. That isn’t true of the class name, method name and line number though. I’m not sure how much extra overhead there is in collecting the module name when you have to collect those to.
>>
>> I should add that when printing exceptions we do cache the file name/location as we are processing the classes for an extended stack trace. We probably will want to add the module name to the extended stack trace as well.
>>
>> Ralph
>>
>>> On Oct 4, 2018, at 10:26 AM, [hidden email] <mailto:[hidden email]> wrote:
>>>
>>> I was thinking about capturing the call stack when you create the logger (to get the module), not when you call the logger.
>>>
>>> cheers,
>>> Rémi
>>>
>>> ----- Mail original -----
>>>> De: "Ralph Goers" <[hidden email]> <mailto:[hidden email]>
>>>> À: "Alex Sviridov" <[hidden email]> <mailto:[hidden email]>
>>>> Cc: "Remi Forax" <[hidden email]> <mailto:[hidden email]>, "jigsaw-dev" <[hidden email]> <mailto:[hidden email]>
>>>> Envoyé: Mercredi 3 Octobre 2018 05:08:27
>>>> Objet: Re: Separate logging for JPMS module/layer
>>>> Log4j handles this by capturing the fully qualified class name of the logging
>>>> adapter. Obviously, this doesn’t work if the adapter doesn’t pass Log4j the
>>>> FQCN, but it does work for the adapters we support.  That said, it is very slow
>>>> to capture this and is probably the biggest pain point. Log4j recommends not
>>>> capturing this information in production environments because it is so slow.
>>>> Unfortunately, it seems to have gotten even slower in Java 9+. In an ideal
>>>> world we would be able to capture the caller information at compile time but
>>>> Java provides no good way to do this. Wouldn’t it be great if I could just code
>>>> something like logger.error(_CallerInfo_, “hello”) and the compiler would
>>>> provide the caller info data structure that was generated by the compiler?
>>>>
>>>> FWIW, I do plan to add the module information to the caller information provided
>>>> with Log4j but just haven’t gotten to it. You are more than welcome to provide
>>>> a patch.
>>>>
>>>> Ralph
>>>>
>>>>> On Oct 2, 2018, at 3:20 PM, Alex Sviridov <[hidden email]> <mailto:[hidden email]> wrote:
>>>>>
>>>>> Thank you for you suggestion. But can this be used when some library
>>>>> uses one logging system and for another uses some bridge. Because of this
>>>>> bridging
>>>>> LoggerFactory.getLogger is called somewhere in bridge, as I understand,
>>>>>
>>>>>
>>>>>> Среда,  3 октября 2018, 1:12 +03:00 от Remi Forax <[hidden email]> <mailto:[hidden email]>:
>>>>>>
>>>>>> You can use the StackWalker
>>>>>> https://docs.oracle.com/en/java/javase/11/docs/api/java.base/java/lang/StackWalker.html <https://docs.oracle.com/en/java/javase/11/docs/api/java.base/java/lang/StackWalker.html>
>>>>>>
>>>>>> regards,
>>>>>> Rémi
>>>>>>
>>>>>> ----- Mail original -----
>>>>>>> De: "Alex Sviridov" < [hidden email] <mailto:[hidden email]> >
>>>>>>> À: "jigsaw-dev" < [hidden email] <mailto:[hidden email]> >
>>>>>>> Envoyé: Mardi 2 Octobre 2018 23:54:48
>>>>>>> Objet: Separate logging for JPMS module/layer
>>>>>>> Hi all,
>>>>>>>
>>>>>>> Could anyone say how the following problem can be solved. I want to create
>>>>>>> separate
>>>>>>> log file for every JPMS module/layer. The problem is that many
>>>>>>> libraries/programs
>>>>>>> use LoggerFactory.getLogger(String className) so in getLogger I have only
>>>>>>> the name of the class as String, so I can't get module and layer.
>>>>>>>
>>>>>>> If I had not String className, but Class klass then the problem would be easily
>>>>>>> solved.
>>>>>>> As I understand I can't load class by name because it would require all modules
>>>>>>> export
>>>>>>> their packages to logging framework that has no sense.
>>>>>>>
>>>>>>> Are there any solutions for such problem?
>>>>>>>
>>>>>>>
>>>>>>> --
>>>>>>> Alex Sviridov
>>>>>
>>>>> --
>>>>> Alex Sviridov
>>
>

Reply | Threaded
Open this post in threaded view
|

Re: Separate logging for JPMS module/layer

Ralph Goers
In reply to this post by Luke Hutchison
Yes, we have found in some situations using the SecurityManager is faster than StackWalker.

Ralph

> On Oct 4, 2018, at 3:08 PM, Luke Hutchison <[hidden email]> wrote:
>
> If you need to read the stack in a manner that is backwards compatible with JDK 8 or earlier, there's also the following mechanism for getting the call stack, by creating a SecurityManager:
>
> https://github.com/classgraph/classgraph/blob/master/src/main/java/io/github/classgraph/utils/CallStackReader.java <https://github.com/classgraph/classgraph/blob/master/src/main/java/io/github/classgraph/utils/CallStackReader.java>
>
> However, is there a reason to believe the above mechanism might stop working in the future?
>
> Under what conditions might SecurityManager not allow RuntimePermission("createSecurityManager") , and how common is this likely to be?
>
> Will there be situations where StackWalker will succeed in reading the call stack but SecurityManager will fail, or vice versa?
>
>
>
> On Thu, Oct 4, 2018 at 3:51 PM Mandy Chung <[hidden email] <mailto:[hidden email]>> wrote:
> If you are looking for the immediate caller, you can try
> StackWalker::getCallerClass which only walks the top few
> frames and intends to be lower cost.
>
> Mandy
>
> On 10/4/18 2:04 PM, Ralph Goers wrote:
> > Hmm, it would probably be a safe assumption that a Logger will never be used outside of the module. That isn’t true of the class name, method name and line number though. I’m not sure how much extra overhead there is in collecting the module name when you have to collect those to.
> >
> > I should add that when printing exceptions we do cache the file name/location as we are processing the classes for an extended stack trace. We probably will want to add the module name to the extended stack trace as well.
> >
> > Ralph
> >
> >> On Oct 4, 2018, at 10:26 AM, [hidden email] <mailto:[hidden email]> wrote:
> >>
> >> I was thinking about capturing the call stack when you create the logger (to get the module), not when you call the logger.
> >>
> >> cheers,
> >> Rémi
> >>
> >> ----- Mail original -----
> >>> De: "Ralph Goers" <[hidden email] <mailto:[hidden email]>>
> >>> À: "Alex Sviridov" <[hidden email] <mailto:[hidden email]>>
> >>> Cc: "Remi Forax" <[hidden email] <mailto:[hidden email]>>, "jigsaw-dev" <[hidden email] <mailto:[hidden email]>>
> >>> Envoyé: Mercredi 3 Octobre 2018 05:08:27
> >>> Objet: Re: Separate logging for JPMS module/layer
> >>> Log4j handles this by capturing the fully qualified class name of the logging
> >>> adapter. Obviously, this doesn’t work if the adapter doesn’t pass Log4j the
> >>> FQCN, but it does work for the adapters we support.  That said, it is very slow
> >>> to capture this and is probably the biggest pain point. Log4j recommends not
> >>> capturing this information in production environments because it is so slow.
> >>> Unfortunately, it seems to have gotten even slower in Java 9+. In an ideal
> >>> world we would be able to capture the caller information at compile time but
> >>> Java provides no good way to do this. Wouldn’t it be great if I could just code
> >>> something like logger.error(_CallerInfo_, “hello”) and the compiler would
> >>> provide the caller info data structure that was generated by the compiler?
> >>>
> >>> FWIW, I do plan to add the module information to the caller information provided
> >>> with Log4j but just haven’t gotten to it. You are more than welcome to provide
> >>> a patch.
> >>>
> >>> Ralph
> >>>
> >>>> On Oct 2, 2018, at 3:20 PM, Alex Sviridov <[hidden email] <mailto:[hidden email]>> wrote:
> >>>>
> >>>> Thank you for you suggestion. But can this be used when some library
> >>>> uses one logging system and for another uses some bridge. Because of this
> >>>> bridging
> >>>> LoggerFactory.getLogger is called somewhere in bridge, as I understand,
> >>>>
> >>>>
> >>>>> Среда,  3 октября 2018, 1:12 +03:00 от Remi Forax <[hidden email] <mailto:[hidden email]>>:
> >>>>>
> >>>>> You can use the StackWalker
> >>>>> https://docs.oracle.com/en/java/javase/11/docs/api/java.base/java/lang/StackWalker.html <https://docs.oracle.com/en/java/javase/11/docs/api/java.base/java/lang/StackWalker.html>
> >>>>>
> >>>>> regards,
> >>>>> Rémi
> >>>>>
> >>>>> ----- Mail original -----
> >>>>>> De: "Alex Sviridov" < [hidden email] <mailto:[hidden email]> >
> >>>>>> À: "jigsaw-dev" < [hidden email] <mailto:[hidden email]> >
> >>>>>> Envoyé: Mardi 2 Octobre 2018 23:54:48
> >>>>>> Objet: Separate logging for JPMS module/layer
> >>>>>> Hi all,
> >>>>>>
> >>>>>> Could anyone say how the following problem can be solved. I want to create
> >>>>>> separate
> >>>>>> log file for every JPMS module/layer. The problem is that many
> >>>>>> libraries/programs
> >>>>>> use LoggerFactory.getLogger(String className) so in getLogger I have only
> >>>>>> the name of the class as String, so I can't get module and layer.
> >>>>>>
> >>>>>> If I had not String className, but Class klass then the problem would be easily
> >>>>>> solved.
> >>>>>> As I understand I can't load class by name because it would require all modules
> >>>>>> export
> >>>>>> their packages to logging framework that has no sense.
> >>>>>>
> >>>>>> Are there any solutions for such problem?
> >>>>>>
> >>>>>>
> >>>>>> --
> >>>>>> Alex Sviridov
> >>>>
> >>>> --
> >>>> Alex Sviridov
> >
>

Reply | Threaded
Open this post in threaded view
|

Re: Separate logging for JPMS module/layer

Ralph Goers
In reply to this post by Ralph Goers
I should have rephrased this. We cannot assume that the caller of the Log4j API method is the caller we need. It might be another Log4j API method or another logging Adapter. Since walking the stack trace is relatively slow we have to defer doing it until we absolutely need to. This generally means we are not walking only a few frames. We have run benchmarks that show using SecurityManager to find the caller class is faster than using StackWalker.

https://lists.apache.org/thread.html/29ca67b98c8a508f2836301ac33747b72ca0ce86f69f466073412bfc@%3Cdev.logging.apache.org%3E <https://lists.apache.org/thread.html/29ca67b98c8a508f2836301ac33747b72ca0ce86f69f466073412bfc@%3Cdev.logging.apache.org%3E>

Ralph

> On Oct 4, 2018, at 9:25 PM, Ralph Goers <[hidden email]> wrote:
>
> Unfortunately, we can’t use getCallerClass. Some API methods can be called by users of the API or by other methods in the API class.
>
> Ralph
>
>> On Oct 4, 2018, at 2:50 PM, Mandy Chung <[hidden email] <mailto:[hidden email]>> wrote:
>>
>> If you are looking for the immediate caller, you can try
>> StackWalker::getCallerClass which only walks the top few
>> frames and intends to be lower cost.
>>
>> Mandy
>>
>> On 10/4/18 2:04 PM, Ralph Goers wrote:
>>> Hmm, it would probably be a safe assumption that a Logger will never be used outside of the module. That isn’t true of the class name, method name and line number though. I’m not sure how much extra overhead there is in collecting the module name when you have to collect those to.
>>>
>>> I should add that when printing exceptions we do cache the file name/location as we are processing the classes for an extended stack trace. We probably will want to add the module name to the extended stack trace as well.
>>>
>>> Ralph
>>>
>>>> On Oct 4, 2018, at 10:26 AM, [hidden email] <mailto:[hidden email]> wrote:
>>>>
>>>> I was thinking about capturing the call stack when you create the logger (to get the module), not when you call the logger.
>>>>
>>>> cheers,
>>>> Rémi
>>>>
>>>> ----- Mail original -----
>>>>> De: "Ralph Goers" <[hidden email]> <mailto:[hidden email]>
>>>>> À: "Alex Sviridov" <[hidden email]> <mailto:[hidden email]>
>>>>> Cc: "Remi Forax" <[hidden email]> <mailto:[hidden email]>, "jigsaw-dev" <[hidden email]> <mailto:[hidden email]>
>>>>> Envoyé: Mercredi 3 Octobre 2018 05:08:27
>>>>> Objet: Re: Separate logging for JPMS module/layer
>>>>> Log4j handles this by capturing the fully qualified class name of the logging
>>>>> adapter. Obviously, this doesn’t work if the adapter doesn’t pass Log4j the
>>>>> FQCN, but it does work for the adapters we support.  That said, it is very slow
>>>>> to capture this and is probably the biggest pain point. Log4j recommends not
>>>>> capturing this information in production environments because it is so slow.
>>>>> Unfortunately, it seems to have gotten even slower in Java 9+. In an ideal
>>>>> world we would be able to capture the caller information at compile time but
>>>>> Java provides no good way to do this. Wouldn’t it be great if I could just code
>>>>> something like logger.error(_CallerInfo_, “hello”) and the compiler would
>>>>> provide the caller info data structure that was generated by the compiler?
>>>>>
>>>>> FWIW, I do plan to add the module information to the caller information provided
>>>>> with Log4j but just haven’t gotten to it. You are more than welcome to provide
>>>>> a patch.
>>>>>
>>>>> Ralph
>>>>>
>>>>>> On Oct 2, 2018, at 3:20 PM, Alex Sviridov <[hidden email]> <mailto:[hidden email]> wrote:
>>>>>>
>>>>>> Thank you for you suggestion. But can this be used when some library
>>>>>> uses one logging system and for another uses some bridge. Because of this
>>>>>> bridging
>>>>>> LoggerFactory.getLogger is called somewhere in bridge, as I understand,
>>>>>>
>>>>>>
>>>>>>> Среда,  3 октября 2018, 1:12 +03:00 от Remi Forax <[hidden email]> <mailto:[hidden email]>:
>>>>>>>
>>>>>>> You can use the StackWalker
>>>>>>> https://docs.oracle.com/en/java/javase/11/docs/api/java.base/java/lang/StackWalker.html <https://docs.oracle.com/en/java/javase/11/docs/api/java.base/java/lang/StackWalker.html>
>>>>>>>
>>>>>>> regards,
>>>>>>> Rémi
>>>>>>>
>>>>>>> ----- Mail original -----
>>>>>>>> De: "Alex Sviridov" < [hidden email] <mailto:[hidden email]> >
>>>>>>>> À: "jigsaw-dev" < [hidden email] <mailto:[hidden email]> >
>>>>>>>> Envoyé: Mardi 2 Octobre 2018 23:54:48
>>>>>>>> Objet: Separate logging for JPMS module/layer
>>>>>>>> Hi all,
>>>>>>>>
>>>>>>>> Could anyone say how the following problem can be solved. I want to create
>>>>>>>> separate
>>>>>>>> log file for every JPMS module/layer. The problem is that many
>>>>>>>> libraries/programs
>>>>>>>> use LoggerFactory.getLogger(String className) so in getLogger I have only
>>>>>>>> the name of the class as String, so I can't get module and layer.
>>>>>>>>
>>>>>>>> If I had not String className, but Class klass then the problem would be easily
>>>>>>>> solved.
>>>>>>>> As I understand I can't load class by name because it would require all modules
>>>>>>>> export
>>>>>>>> their packages to logging framework that has no sense.
>>>>>>>>
>>>>>>>> Are there any solutions for such problem?
>>>>>>>>
>>>>>>>>
>>>>>>>> --
>>>>>>>> Alex Sviridov
>>>>>> --
>>>>>> Alex Sviridov
>>
>

Reply | Threaded
Open this post in threaded view
|

Re: Separate logging for JPMS module/layer

Luke Hutchison
In reply to this post by Ralph Goers
On Thu, Oct 4, 2018, 10:27 PM Ralph Goers <[hidden email]> wrote:

> Yes, we have found in some situations using the SecurityManager is faster
> than StackWalker.
>

This is interesting -- how much slower is StackWalker in these situations,
and under what condition is there a speed difference?

Have you seen SecurityManager omit important stack frames, as Mandy
suggested might happen?

Have you seen situations where the SecurityManager solution doesn't work
(due to security permissions), but the StackWalker does work?
Reply | Threaded
Open this post in threaded view
|

Re: Separate logging for JPMS module/layer

Ralph Goers


> On Oct 5, 2018, at 1:10 AM, Luke Hutchison <[hidden email]> wrote:
>
> On Thu, Oct 4, 2018, 10:27 PM Ralph Goers <[hidden email] <mailto:[hidden email]>> wrote:
> Yes, we have found in some situations using the SecurityManager is faster than StackWalker.
>
> This is interesting -- how much slower is StackWalker in these situations, and under what condition is there a speed difference?

Benchmark Mode Cnt Score Error Units StackTraceBenchmark.defaultJava8 thrpt 3 113965.921 ± 119706.986 ops/s StackTraceBenchmark.securityManager thrpt 3 788004.237 ± 82578.567 ops/s StackTraceBenchmark.stackWalker thrpt 3 182902.031 ± 39018.395 ops/s



>
> Have you seen SecurityManager omit important stack frames, as Mandy suggested might happen?

No.

>
> Have you seen situations where the SecurityManager solution doesn't work (due to security permissions), but the StackWalker does work?

No one has ever complained. However, our code will fall back to other mechanisms if SecurityManager doesn’t work.


Ralph

Reply | Threaded
Open this post in threaded view
|

Re: Separate logging for JPMS module/layer

David Lloyd
On Fri, Oct 5, 2018 at 10:12 AM Ralph Goers <[hidden email]> wrote:

> > On Oct 5, 2018, at 1:10 AM, Luke Hutchison <[hidden email]> wrote:
> >
> > On Thu, Oct 4, 2018, 10:27 PM Ralph Goers <[hidden email] <mailto:[hidden email]>> wrote:
> > Yes, we have found in some situations using the SecurityManager is faster than StackWalker.
> >
> > This is interesting -- how much slower is StackWalker in these situations, and under what condition is there a speed difference?
>
> Benchmark Mode Cnt Score Error Units
> StackTraceBenchmark.defaultJava8 thrpt 3 113965.921 ± 119706.986 ops/s
> StackTraceBenchmark.securityManager thrpt 3 788004.237 ± 82578.567 ops/s
> StackTraceBenchmark.stackWalker thrpt 3 182902.031 ± 39018.395 ops/s

Something to consider is _how_ the StackWalker is used.  It's
potentially quite expensive in that it produces a Stream in its full
usage mode.  Have you compared using the stream + lambda approach
versus extracting the stream iterator and iterating in the classic
Java fashion?  I doubt it would make the benchmark competitive, but it
might help a little bit.

In the end, StackWalker does a relatively large amount of work and
performs substantially more object allocations than the simpler
classical approaches.  Extracting any decent performance of
StackWalker would probably be highly contingent on successful compiler
optimizations like devirtualizing and inlining the stream processing,
deleting unused allocations, etc.  In practice these kinds of
optimizations seem very finicky and quite easy to inadvertently
defeat, which is why I've always been skeptical about the Stream
approach.  Maybe the iterator has potential to be slightly better, or
could be made to do so.

--
- DML
12