Idea on how to speed up ClassLoaderContextSelector

[Matt Sicker <bo...@gmail.com>]

I tried this idea out and it looked like it worked fine, but I thought I'd
propose it here first before making any changes. There are a couple methods
in LogManager that take a Class instead of a String for the logger name. I
think that the provided class's ClassLoader should be passed along in the
appropriate parameters from there and not just ignored. That way, when the
ClassLoaderContextSelector is invoked, it will have a ClassLoader provided
to it already and can determine the appropriate LoggerContext without
having to use reflection.

Now I'd probably want to write a microbenchmark first before really
considering this idea, but it's not very complicated. However, this is
really only invoked once per class approximately (provided you store the
Logger as a static field), and if for some reason the user uses a Class
that isn't using in the same ClassLoader as the calling Class, then it
might cause weird issues. Then again, I might expect as a user that calling
LogManager.getLogger(String.class), for instance, would give me the same
Logger no matter what ClassLoader was used provided it's all on the same
JVM.

Thoughts?

P.S. I was playing with the microbenchmarks last night and found this to be
really awesome! I'm going to add some other benchmarks and migrate the
remaining unit tests we have that are purely for benchmarking purposes into
the log4j-perf module. There's no need to run performance tests in our unit
tests when they don't even verify anything about the output!

-- 
Matt Sicker <bo...@gmail.com>

Re: Idea on how to speed up ClassLoaderContextSelector

[Remko Popma <re...@gmail.com>]

2.1 sounds fine to me. 

Sent from my iPhone

> On 2014/08/04, at 10:21, Matt Sicker <bo...@gmail.com> wrote:
> 
> Well, such a change can wait for 2.1, right? It could have strange consequences if included in a patch release. :)
> 
> 
>> On 3 August 2014 19:33, Ralph Goers <ra...@dslextreme.com> wrote:
>> Yes.
>> 
>>> On Aug 3, 2014, at 3:18 PM, Matt Sicker <bo...@gmail.com> wrote:
>>> 
>>> Which suggestion? The one about using the provided Class's ClassLoader in LogManager?
>>> 
>>> 
>>>> On 3 August 2014 02:48, Ralph Goers <ra...@dslextreme.com> wrote:
>>>> Yes, ClassLoaderContextSelector isn’t terribly fast.  To be honest I made it the default because I wanted to get feedback on how well it worked or if it caused issues.  I have been pleasantly surprised that there really haven’t been any serious issues reported on it.
>>>> 
>>>> Over the life of an application though you would only expect thousands of unique Loggers at the most, so the creation time over the lifetime of the application probably doesn’t matter much.  However, if the application creates Loggers when classes are created and a lot of them are created at startup then this could impact startup time significantly.  For that reason I would encourage finding a way to do what Matt is suggesting. I had actually thought of it myself but just never got around to it.
>>>> 
>>>> Ralph
>>>> 
>>>>> On Aug 2, 2014, at 8:05 PM, Remko Popma <re...@gmail.com> wrote:
>>>>> 
>>>>> Thanks for bringing it up here first.
>>>>> 
>>>>> I have a question: is this beneficial for envs like OSGi and web apps, or are you aiming for a general speedup?
>>>>> Generally I try to optimize the heck out of things that are called all the time, but usually don't bother with code that is run only once. That said, if we can cut the startup time in half or so that would be worth doing. So I guess it depends on how much of a speedup we gain. (Of course, it if makes the code simpler, it may be worth doing anyway...)
>>>>> 
>>>>> Completely agree that microbenchmarks are very useful to help us make decisions based on facts instead of intuition.
>>>>> (One thing I am learning is that it is worth running benchmarks with one thread as well as multiple threads, and also to run in multiple OS-es if possible: that thing with System.currentTimeMillis being so much more expensive under Linux was a big surprise for me.)
>>>>> 
>>>>> 
>>>>> 
>>>>>> On Sun, Aug 3, 2014 at 9:34 AM, Matt Sicker <bo...@gmail.com> wrote:
>>>>>> I tried this idea out and it looked like it worked fine, but I thought I'd propose it here first before making any changes. There are a couple methods in LogManager that take a Class instead of a String for the logger name. I think that the provided class's ClassLoader should be passed along in the appropriate parameters from there and not just ignored. That way, when the ClassLoaderContextSelector is invoked, it will have a ClassLoader provided to it already and can determine the appropriate LoggerContext without having to use reflection.
>>>>>> 
>>>>>> Now I'd probably want to write a microbenchmark first before really considering this idea, but it's not very complicated. However, this is really only invoked once per class approximately (provided you store the Logger as a static field), and if for some reason the user uses a Class that isn't using in the same ClassLoader as the calling Class, then it might cause weird issues. Then again, I might expect as a user that calling LogManager.getLogger(String.class), for instance, would give me the same Logger no matter what ClassLoader was used provided it's all on the same JVM.
>>>>>> 
>>>>>> Thoughts?
>>>>>> 
>>>>>> P.S. I was playing with the microbenchmarks last night and found this to be really awesome! I'm going to add some other benchmarks and migrate the remaining unit tests we have that are purely for benchmarking purposes into the log4j-perf module. There's no need to run performance tests in our unit tests when they don't even verify anything about the output!
>>>>>> 
>>>>>> -- 
>>>>>> Matt Sicker <bo...@gmail.com>
>>>>> 
>>>> 
>>> 
>>> 
>>> 
>>> -- 
>>> Matt Sicker <bo...@gmail.com>
>> 
> 
> 
> 
> -- 
> Matt Sicker <bo...@gmail.com>

Re: Idea on how to speed up ClassLoaderContextSelector

[Matt Sicker <bo...@gmail.com>]

Well, such a change can wait for 2.1, right? It could have strange
consequences if included in a patch release. :)


On 3 August 2014 19:33, Ralph Goers <ra...@dslextreme.com> wrote:

> Yes.
>
> On Aug 3, 2014, at 3:18 PM, Matt Sicker <bo...@gmail.com> wrote:
>
> Which suggestion? The one about using the provided Class's ClassLoader in
> LogManager?
>
>
> On 3 August 2014 02:48, Ralph Goers <ra...@dslextreme.com> wrote:
>
>> Yes, ClassLoaderContextSelector isn’t terribly fast.  To be honest I made
>> it the default because I wanted to get feedback on how well it worked or if
>> it caused issues.  I have been pleasantly surprised that there really
>> haven’t been any serious issues reported on it.
>>
>> Over the life of an application though you would only expect thousands of
>> unique Loggers at the most, so the creation time over the lifetime of the
>> application probably doesn’t matter much.  However, if the application
>> creates Loggers when classes are created and a lot of them are created at
>> startup then this could impact startup time significantly.  For that reason
>> I would encourage finding a way to do what Matt is suggesting. I had
>> actually thought of it myself but just never got around to it.
>>
>> Ralph
>>
>> On Aug 2, 2014, at 8:05 PM, Remko Popma <re...@gmail.com> wrote:
>>
>> Thanks for bringing it up here first.
>>
>> I have a question: is this beneficial for envs like OSGi and web apps, or
>> are you aiming for a general speedup?
>> Generally I try to optimize the heck out of things that are called all
>> the time, but usually don't bother with code that is run only once. That
>> said, if we can cut the startup time in half or so that would be worth
>> doing. So I guess it depends on how much of a speedup we gain. (Of course,
>> it if makes the code simpler, it may be worth doing anyway...)
>>
>> Completely agree that microbenchmarks are very useful to help us make
>> decisions based on facts instead of intuition.
>> (One thing I am learning is that it is worth running benchmarks with one
>> thread as well as multiple threads, and also to run in multiple OS-es if
>> possible: that thing with System.currentTimeMillis being so much more
>> expensive under Linux was a big surprise for me.)
>>
>>
>>
>> On Sun, Aug 3, 2014 at 9:34 AM, Matt Sicker <bo...@gmail.com> wrote:
>>
>>> I tried this idea out and it looked like it worked fine, but I thought
>>> I'd propose it here first before making any changes. There are a couple
>>> methods in LogManager that take a Class instead of a String for the logger
>>> name. I think that the provided class's ClassLoader should be passed along
>>> in the appropriate parameters from there and not just ignored. That way,
>>> when the ClassLoaderContextSelector is invoked, it will have a ClassLoader
>>> provided to it already and can determine the appropriate LoggerContext
>>> without having to use reflection.
>>>
>>> Now I'd probably want to write a microbenchmark first before really
>>> considering this idea, but it's not very complicated. However, this is
>>> really only invoked once per class approximately (provided you store the
>>> Logger as a static field), and if for some reason the user uses a Class
>>> that isn't using in the same ClassLoader as the calling Class, then it
>>> might cause weird issues. Then again, I might expect as a user that calling
>>> LogManager.getLogger(String.class), for instance, would give me the same
>>> Logger no matter what ClassLoader was used provided it's all on the same
>>> JVM.
>>>
>>> Thoughts?
>>>
>>> P.S. I was playing with the microbenchmarks last night and found this to
>>> be really awesome! I'm going to add some other benchmarks and migrate the
>>> remaining unit tests we have that are purely for benchmarking purposes into
>>> the log4j-perf module. There's no need to run performance tests in our unit
>>> tests when they don't even verify anything about the output!
>>>
>>> --
>>> Matt Sicker <bo...@gmail.com>
>>>
>>
>>
>>
>
>
> --
> Matt Sicker <bo...@gmail.com>
>
>
>


-- 
Matt Sicker <bo...@gmail.com>

Re: Idea on how to speed up ClassLoaderContextSelector

[Ralph Goers <ra...@dslextreme.com>]

Yes.

On Aug 3, 2014, at 3:18 PM, Matt Sicker <bo...@gmail.com> wrote:

> Which suggestion? The one about using the provided Class's ClassLoader in LogManager?
> 
> 
> On 3 August 2014 02:48, Ralph Goers <ra...@dslextreme.com> wrote:
> Yes, ClassLoaderContextSelector isn’t terribly fast.  To be honest I made it the default because I wanted to get feedback on how well it worked or if it caused issues.  I have been pleasantly surprised that there really haven’t been any serious issues reported on it.
> 
> Over the life of an application though you would only expect thousands of unique Loggers at the most, so the creation time over the lifetime of the application probably doesn’t matter much.  However, if the application creates Loggers when classes are created and a lot of them are created at startup then this could impact startup time significantly.  For that reason I would encourage finding a way to do what Matt is suggesting. I had actually thought of it myself but just never got around to it.
> 
> Ralph
> 
> On Aug 2, 2014, at 8:05 PM, Remko Popma <re...@gmail.com> wrote:
> 
>> Thanks for bringing it up here first.
>> 
>> I have a question: is this beneficial for envs like OSGi and web apps, or are you aiming for a general speedup?
>> Generally I try to optimize the heck out of things that are called all the time, but usually don't bother with code that is run only once. That said, if we can cut the startup time in half or so that would be worth doing. So I guess it depends on how much of a speedup we gain. (Of course, it if makes the code simpler, it may be worth doing anyway...)
>> 
>> Completely agree that microbenchmarks are very useful to help us make decisions based on facts instead of intuition.
>> (One thing I am learning is that it is worth running benchmarks with one thread as well as multiple threads, and also to run in multiple OS-es if possible: that thing with System.currentTimeMillis being so much more expensive under Linux was a big surprise for me.)
>> 
>> 
>> 
>> On Sun, Aug 3, 2014 at 9:34 AM, Matt Sicker <bo...@gmail.com> wrote:
>> I tried this idea out and it looked like it worked fine, but I thought I'd propose it here first before making any changes. There are a couple methods in LogManager that take a Class instead of a String for the logger name. I think that the provided class's ClassLoader should be passed along in the appropriate parameters from there and not just ignored. That way, when the ClassLoaderContextSelector is invoked, it will have a ClassLoader provided to it already and can determine the appropriate LoggerContext without having to use reflection.
>> 
>> Now I'd probably want to write a microbenchmark first before really considering this idea, but it's not very complicated. However, this is really only invoked once per class approximately (provided you store the Logger as a static field), and if for some reason the user uses a Class that isn't using in the same ClassLoader as the calling Class, then it might cause weird issues. Then again, I might expect as a user that calling LogManager.getLogger(String.class), for instance, would give me the same Logger no matter what ClassLoader was used provided it's all on the same JVM.
>> 
>> Thoughts?
>> 
>> P.S. I was playing with the microbenchmarks last night and found this to be really awesome! I'm going to add some other benchmarks and migrate the remaining unit tests we have that are purely for benchmarking purposes into the log4j-perf module. There's no need to run performance tests in our unit tests when they don't even verify anything about the output!
>> 
>> -- 
>> Matt Sicker <bo...@gmail.com>
>> 
> 
> 
> 
> 
> -- 
> Matt Sicker <bo...@gmail.com>

Re: Idea on how to speed up ClassLoaderContextSelector

[Matt Sicker <bo...@gmail.com>]

Which suggestion? The one about using the provided Class's ClassLoader in
LogManager?


On 3 August 2014 02:48, Ralph Goers <ra...@dslextreme.com> wrote:

> Yes, ClassLoaderContextSelector isn’t terribly fast.  To be honest I made
> it the default because I wanted to get feedback on how well it worked or if
> it caused issues.  I have been pleasantly surprised that there really
> haven’t been any serious issues reported on it.
>
> Over the life of an application though you would only expect thousands of
> unique Loggers at the most, so the creation time over the lifetime of the
> application probably doesn’t matter much.  However, if the application
> creates Loggers when classes are created and a lot of them are created at
> startup then this could impact startup time significantly.  For that reason
> I would encourage finding a way to do what Matt is suggesting. I had
> actually thought of it myself but just never got around to it.
>
> Ralph
>
> On Aug 2, 2014, at 8:05 PM, Remko Popma <re...@gmail.com> wrote:
>
> Thanks for bringing it up here first.
>
> I have a question: is this beneficial for envs like OSGi and web apps, or
> are you aiming for a general speedup?
> Generally I try to optimize the heck out of things that are called all the
> time, but usually don't bother with code that is run only once. That said,
> if we can cut the startup time in half or so that would be worth doing. So
> I guess it depends on how much of a speedup we gain. (Of course, it if
> makes the code simpler, it may be worth doing anyway...)
>
> Completely agree that microbenchmarks are very useful to help us make
> decisions based on facts instead of intuition.
> (One thing I am learning is that it is worth running benchmarks with one
> thread as well as multiple threads, and also to run in multiple OS-es if
> possible: that thing with System.currentTimeMillis being so much more
> expensive under Linux was a big surprise for me.)
>
>
>
> On Sun, Aug 3, 2014 at 9:34 AM, Matt Sicker <bo...@gmail.com> wrote:
>
>> I tried this idea out and it looked like it worked fine, but I thought
>> I'd propose it here first before making any changes. There are a couple
>> methods in LogManager that take a Class instead of a String for the logger
>> name. I think that the provided class's ClassLoader should be passed along
>> in the appropriate parameters from there and not just ignored. That way,
>> when the ClassLoaderContextSelector is invoked, it will have a ClassLoader
>> provided to it already and can determine the appropriate LoggerContext
>> without having to use reflection.
>>
>> Now I'd probably want to write a microbenchmark first before really
>> considering this idea, but it's not very complicated. However, this is
>> really only invoked once per class approximately (provided you store the
>> Logger as a static field), and if for some reason the user uses a Class
>> that isn't using in the same ClassLoader as the calling Class, then it
>> might cause weird issues. Then again, I might expect as a user that calling
>> LogManager.getLogger(String.class), for instance, would give me the same
>> Logger no matter what ClassLoader was used provided it's all on the same
>> JVM.
>>
>> Thoughts?
>>
>> P.S. I was playing with the microbenchmarks last night and found this to
>> be really awesome! I'm going to add some other benchmarks and migrate the
>> remaining unit tests we have that are purely for benchmarking purposes into
>> the log4j-perf module. There's no need to run performance tests in our unit
>> tests when they don't even verify anything about the output!
>>
>> --
>> Matt Sicker <bo...@gmail.com>
>>
>
>
>


-- 
Matt Sicker <bo...@gmail.com>

Re: Idea on how to speed up ClassLoaderContextSelector

[Ralph Goers <ra...@dslextreme.com>]

Yes, ClassLoaderContextSelector isn’t terribly fast.  To be honest I made it the default because I wanted to get feedback on how well it worked or if it caused issues.  I have been pleasantly surprised that there really haven’t been any serious issues reported on it.

Over the life of an application though you would only expect thousands of unique Loggers at the most, so the creation time over the lifetime of the application probably doesn’t matter much.  However, if the application creates Loggers when classes are created and a lot of them are created at startup then this could impact startup time significantly.  For that reason I would encourage finding a way to do what Matt is suggesting. I had actually thought of it myself but just never got around to it.

Ralph

On Aug 2, 2014, at 8:05 PM, Remko Popma <re...@gmail.com> wrote:

> Thanks for bringing it up here first.
> 
> I have a question: is this beneficial for envs like OSGi and web apps, or are you aiming for a general speedup?
> Generally I try to optimize the heck out of things that are called all the time, but usually don't bother with code that is run only once. That said, if we can cut the startup time in half or so that would be worth doing. So I guess it depends on how much of a speedup we gain. (Of course, it if makes the code simpler, it may be worth doing anyway...)
> 
> Completely agree that microbenchmarks are very useful to help us make decisions based on facts instead of intuition.
> (One thing I am learning is that it is worth running benchmarks with one thread as well as multiple threads, and also to run in multiple OS-es if possible: that thing with System.currentTimeMillis being so much more expensive under Linux was a big surprise for me.)
> 
> 
> 
> On Sun, Aug 3, 2014 at 9:34 AM, Matt Sicker <bo...@gmail.com> wrote:
> I tried this idea out and it looked like it worked fine, but I thought I'd propose it here first before making any changes. There are a couple methods in LogManager that take a Class instead of a String for the logger name. I think that the provided class's ClassLoader should be passed along in the appropriate parameters from there and not just ignored. That way, when the ClassLoaderContextSelector is invoked, it will have a ClassLoader provided to it already and can determine the appropriate LoggerContext without having to use reflection.
> 
> Now I'd probably want to write a microbenchmark first before really considering this idea, but it's not very complicated. However, this is really only invoked once per class approximately (provided you store the Logger as a static field), and if for some reason the user uses a Class that isn't using in the same ClassLoader as the calling Class, then it might cause weird issues. Then again, I might expect as a user that calling LogManager.getLogger(String.class), for instance, would give me the same Logger no matter what ClassLoader was used provided it's all on the same JVM.
> 
> Thoughts?
> 
> P.S. I was playing with the microbenchmarks last night and found this to be really awesome! I'm going to add some other benchmarks and migrate the remaining unit tests we have that are purely for benchmarking purposes into the log4j-perf module. There's no need to run performance tests in our unit tests when they don't even verify anything about the output!
> 
> -- 
> Matt Sicker <bo...@gmail.com>
> 

Re: Idea on how to speed up ClassLoaderContextSelector

[Matt Sicker <bo...@gmail.com>]

Yeah, it would mostly be for web apps, OSGi, and other places running with
segregated class loaders. But I'd imagine most people will use
LogManager.getLogger() for convenience and not provide the class. However,
ClassLoaderContextSelector is the default ContextSelector. Now if only Java
had a sort of ClassLoaderContext or something. ;)


On 2 August 2014 22:05, Remko Popma <re...@gmail.com> wrote:

> Thanks for bringing it up here first.
>
> I have a question: is this beneficial for envs like OSGi and web apps, or
> are you aiming for a general speedup?
> Generally I try to optimize the heck out of things that are called all the
> time, but usually don't bother with code that is run only once. That said,
> if we can cut the startup time in half or so that would be worth doing. So
> I guess it depends on how much of a speedup we gain. (Of course, it if
> makes the code simpler, it may be worth doing anyway...)
>
> Completely agree that microbenchmarks are very useful to help us make
> decisions based on facts instead of intuition.
> (One thing I am learning is that it is worth running benchmarks with one
> thread as well as multiple threads, and also to run in multiple OS-es if
> possible: that thing with System.currentTimeMillis being so much more
> expensive under Linux was a big surprise for me.)
>
>
>
> On Sun, Aug 3, 2014 at 9:34 AM, Matt Sicker <bo...@gmail.com> wrote:
>
>> I tried this idea out and it looked like it worked fine, but I thought
>> I'd propose it here first before making any changes. There are a couple
>> methods in LogManager that take a Class instead of a String for the logger
>> name. I think that the provided class's ClassLoader should be passed along
>> in the appropriate parameters from there and not just ignored. That way,
>> when the ClassLoaderContextSelector is invoked, it will have a ClassLoader
>> provided to it already and can determine the appropriate LoggerContext
>> without having to use reflection.
>>
>> Now I'd probably want to write a microbenchmark first before really
>> considering this idea, but it's not very complicated. However, this is
>> really only invoked once per class approximately (provided you store the
>> Logger as a static field), and if for some reason the user uses a Class
>> that isn't using in the same ClassLoader as the calling Class, then it
>> might cause weird issues. Then again, I might expect as a user that calling
>> LogManager.getLogger(String.class), for instance, would give me the same
>> Logger no matter what ClassLoader was used provided it's all on the same
>> JVM.
>>
>> Thoughts?
>>
>> P.S. I was playing with the microbenchmarks last night and found this to
>> be really awesome! I'm going to add some other benchmarks and migrate the
>> remaining unit tests we have that are purely for benchmarking purposes into
>> the log4j-perf module. There's no need to run performance tests in our unit
>> tests when they don't even verify anything about the output!
>>
>> --
>> Matt Sicker <bo...@gmail.com>
>>
>
>


-- 
Matt Sicker <bo...@gmail.com>

Re: Idea on how to speed up ClassLoaderContextSelector

[Remko Popma <re...@gmail.com>]

Thanks for bringing it up here first.

I have a question: is this beneficial for envs like OSGi and web apps, or
are you aiming for a general speedup?
Generally I try to optimize the heck out of things that are called all the
time, but usually don't bother with code that is run only once. That said,
if we can cut the startup time in half or so that would be worth doing. So
I guess it depends on how much of a speedup we gain. (Of course, it if
makes the code simpler, it may be worth doing anyway...)

Completely agree that microbenchmarks are very useful to help us make
decisions based on facts instead of intuition.
(One thing I am learning is that it is worth running benchmarks with one
thread as well as multiple threads, and also to run in multiple OS-es if
possible: that thing with System.currentTimeMillis being so much more
expensive under Linux was a big surprise for me.)



On Sun, Aug 3, 2014 at 9:34 AM, Matt Sicker <bo...@gmail.com> wrote:

> I tried this idea out and it looked like it worked fine, but I thought I'd
> propose it here first before making any changes. There are a couple methods
> in LogManager that take a Class instead of a String for the logger name. I
> think that the provided class's ClassLoader should be passed along in the
> appropriate parameters from there and not just ignored. That way, when the
> ClassLoaderContextSelector is invoked, it will have a ClassLoader provided
> to it already and can determine the appropriate LoggerContext without
> having to use reflection.
>
> Now I'd probably want to write a microbenchmark first before really
> considering this idea, but it's not very complicated. However, this is
> really only invoked once per class approximately (provided you store the
> Logger as a static field), and if for some reason the user uses a Class
> that isn't using in the same ClassLoader as the calling Class, then it
> might cause weird issues. Then again, I might expect as a user that calling
> LogManager.getLogger(String.class), for instance, would give me the same
> Logger no matter what ClassLoader was used provided it's all on the same
> JVM.
>
> Thoughts?
>
> P.S. I was playing with the microbenchmarks last night and found this to
> be really awesome! I'm going to add some other benchmarks and migrate the
> remaining unit tests we have that are purely for benchmarking purposes into
> the log4j-perf module. There's no need to run performance tests in our unit
> tests when they don't even verify anything about the output!
>
> --
> Matt Sicker <bo...@gmail.com>
>