Compression of rolled files : performance issue when lots of JVMs are using timed based policy

classic Classic list List threaded Threaded
20 messages Options
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Compression of rolled files : performance issue when lots of JVMs are using timed based policy

Anthony Maire
Hi

We are currently using another logging framework in production, but I'm
pushing to change it for log4j2.

One common issue we have with that framework (and I assume we can have the
same with log4j2) is that all of our JVMs (we can have more than 50 JVMs on
the same server in production) roll their file at midnight.

When this happens, the system became often not usable for a few seconds
because of the simultaneous zipping of all the rolled files that overload
the CPU (although zipping is done in a specific background thread). To
reduce this effect, we are combining a time based rolling policy with a
sized based policy to zip smaller files, but this is not enough to make the
system fully responsive at midnight.

A pretty cool feature for us to avoid this issue is to have the possibility
when a rolling is triggered because of a time based policy to change file
immediately, but to wait for a random amount of time (within a configurable
limit) before starting the compression. This random delay should help a lot
to avoid contention on CPU cycles.

Does log4j2 have something to solve this kind of issue ? If not, would you
accept a pull request for this (I will open a Jira if needed) ?

Regards,
Anthony
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Compression of rolled files : performance issue when lots of JVMs are using timed based policy

Matt Sicker
I'm not sure if the feature is in log4j, but that reminds me of the jenkins
feature where you can do the same. I'd take a look at the cron triggering
policy docs first to see what's already possible. You can also combine that
with some scripts, so there's certainly a way to do it using current
functionality.

On 22 March 2017 at 08:47, Anthony Maire <[hidden email]> wrote:

> Hi
>
> We are currently using another logging framework in production, but I'm
> pushing to change it for log4j2.
>
> One common issue we have with that framework (and I assume we can have the
> same with log4j2) is that all of our JVMs (we can have more than 50 JVMs on
> the same server in production) roll their file at midnight.
>
> When this happens, the system became often not usable for a few seconds
> because of the simultaneous zipping of all the rolled files that overload
> the CPU (although zipping is done in a specific background thread). To
> reduce this effect, we are combining a time based rolling policy with a
> sized based policy to zip smaller files, but this is not enough to make the
> system fully responsive at midnight.
>
> A pretty cool feature for us to avoid this issue is to have the possibility
> when a rolling is triggered because of a time based policy to change file
> immediately, but to wait for a random amount of time (within a configurable
> limit) before starting the compression. This random delay should help a lot
> to avoid contention on CPU cycles.
>
> Does log4j2 have something to solve this kind of issue ? If not, would you
> accept a pull request for this (I will open a Jira if needed) ?
>
> Regards,
> Anthony
>



--
Matt Sicker <[hidden email]>
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Compression of rolled files : performance issue when lots of JVMs are using timed based policy

David Leonhartsberger
I think something like the following is possible
<RollingFileAppende filePattern=12:00:{date:seconds}>

Means that you specify that the rollover should happen at 12:00 but the
seconds are kind of randomized via Property Substitution or so.
Not sure if date:seconds works but alternatively you could use system or
env variables for it i guess.

Br,
David

On Wed, Mar 22, 2017 at 3:18 PM, Matt Sicker <[hidden email]> wrote:

> I'm not sure if the feature is in log4j, but that reminds me of the jenkins
> feature where you can do the same. I'd take a look at the cron triggering
> policy docs first to see what's already possible. You can also combine that
> with some scripts, so there's certainly a way to do it using current
> functionality.
>
> On 22 March 2017 at 08:47, Anthony Maire <[hidden email]> wrote:
>
> > Hi
> >
> > We are currently using another logging framework in production, but I'm
> > pushing to change it for log4j2.
> >
> > One common issue we have with that framework (and I assume we can have
> the
> > same with log4j2) is that all of our JVMs (we can have more than 50 JVMs
> on
> > the same server in production) roll their file at midnight.
> >
> > When this happens, the system became often not usable for a few seconds
> > because of the simultaneous zipping of all the rolled files that overload
> > the CPU (although zipping is done in a specific background thread). To
> > reduce this effect, we are combining a time based rolling policy with a
> > sized based policy to zip smaller files, but this is not enough to make
> the
> > system fully responsive at midnight.
> >
> > A pretty cool feature for us to avoid this issue is to have the
> possibility
> > when a rolling is triggered because of a time based policy to change file
> > immediately, but to wait for a random amount of time (within a
> configurable
> > limit) before starting the compression. This random delay should help a
> lot
> > to avoid contention on CPU cycles.
> >
> > Does log4j2 have something to solve this kind of issue ? If not, would
> you
> > accept a pull request for this (I will open a Jira if needed) ?
> >
> > Regards,
> > Anthony
> >
>
>
>
> --
> Matt Sicker <[hidden email]>
>
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Compression of rolled files : performance issue when lots of JVMs are using timed based policy

Greg Thomas-2
In reply to this post by Anthony Maire
>One common issue we have with that framework (and I assume we can have the
>same with log4j2) is that all of our JVMs (we can have more than 50 JVMs on
>the same server in production) roll their file at midnight.
>
>When this happens, the system became often not usable for a few seconds
>because of the simultaneous zipping of all the rolled files that overload
>the CPU (although zipping is done in a specific background thread).

ISTR that with the most recent versions of log4j, these threads are in a
thread pool so that they are properly shutdown at the right time. I wonder
if it's possible (or could be possible) to somehow inject a thread pool in
to log4j for this rollover, so that for you use case you could inject a
single thread executor, so only one thread is ever compressing at a time.

Just a thought, anyway,

Greg

On 22 March 2017 at 13:47, Anthony Maire <[hidden email]> wrote:

> Hi
>
> We are currently using another logging framework in production, but I'm
> pushing to change it for log4j2.
>
> One common issue we have with that framework (and I assume we can have the
> same with log4j2) is that all of our JVMs (we can have more than 50 JVMs on
> the same server in production) roll their file at midnight.
>
> When this happens, the system became often not usable for a few seconds
> because of the simultaneous zipping of all the rolled files that overload
> the CPU (although zipping is done in a specific background thread). To
> reduce this effect, we are combining a time based rolling policy with a
> sized based policy to zip smaller files, but this is not enough to make the
> system fully responsive at midnight.
>
> A pretty cool feature for us to avoid this issue is to have the possibility
> when a rolling is triggered because of a time based policy to change file
> immediately, but to wait for a random amount of time (within a configurable
> limit) before starting the compression. This random delay should help a lot
> to avoid contention on CPU cycles.
>
> Does log4j2 have something to solve this kind of issue ? If not, would you
> accept a pull request for this (I will open a Jira if needed) ?
>
> Regards,
> Anthony
>
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Compression of rolled files : performance issue when lots of JVMs are using timed based policy

Ralph Goers
These are separate JVMs, so having a single executor would be of no help.

I believe the only way to do what you are asking for is to add configuration so that the asynchronous thread has a semi-random delay when it starts.

Ralph

> On Mar 22, 2017, at 7:58 AM, Greg Thomas <[hidden email]> wrote:
>
>> One common issue we have with that framework (and I assume we can have the
>> same with log4j2) is that all of our JVMs (we can have more than 50 JVMs on
>> the same server in production) roll their file at midnight.
>>
>> When this happens, the system became often not usable for a few seconds
>> because of the simultaneous zipping of all the rolled files that overload
>> the CPU (although zipping is done in a specific background thread).
>
> ISTR that with the most recent versions of log4j, these threads are in a
> thread pool so that they are properly shutdown at the right time. I wonder
> if it's possible (or could be possible) to somehow inject a thread pool in
> to log4j for this rollover, so that for you use case you could inject a
> single thread executor, so only one thread is ever compressing at a time.
>
> Just a thought, anyway,
>
> Greg
>
> On 22 March 2017 at 13:47, Anthony Maire <[hidden email]> wrote:
>
>> Hi
>>
>> We are currently using another logging framework in production, but I'm
>> pushing to change it for log4j2.
>>
>> One common issue we have with that framework (and I assume we can have the
>> same with log4j2) is that all of our JVMs (we can have more than 50 JVMs on
>> the same server in production) roll their file at midnight.
>>
>> When this happens, the system became often not usable for a few seconds
>> because of the simultaneous zipping of all the rolled files that overload
>> the CPU (although zipping is done in a specific background thread). To
>> reduce this effect, we are combining a time based rolling policy with a
>> sized based policy to zip smaller files, but this is not enough to make the
>> system fully responsive at midnight.
>>
>> A pretty cool feature for us to avoid this issue is to have the possibility
>> when a rolling is triggered because of a time based policy to change file
>> immediately, but to wait for a random amount of time (within a configurable
>> limit) before starting the compression. This random delay should help a lot
>> to avoid contention on CPU cycles.
>>
>> Does log4j2 have something to solve this kind of issue ? If not, would you
>> accept a pull request for this (I will open a Jira if needed) ?
>>
>> Regards,
>> Anthony
>>



---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Compression of rolled files : performance issue when lots of JVMs are using timed based policy

Anthony Maire
Thanks for these answers

@Ralph : that was the kind of idea I had in mind : changing the
RollingFileManager.asyncExecutor to be a ScheduledThreadPoolExecutor, and
based on some configuration, submitting task to be executed after a random
delay. However with this kind of approach, special treatment should be made
if the manager is stopped with some pending delayed tasks in it.

@Matt : Cron policy can be a solution, but I don't know how to inject some
random element in this to make the file roll at midnight + X random
seconds. Since there is a lot of JVM to manage and some of them can be
moved from a machine to another, I need to have a single log4j2.xml file
for all environments. Moreover, our system administrators are reluctant to
have something based on a shell-specific feature (such has the $RANDOM
variable from bash)

Anthony

2017-03-22 16:31 GMT+01:00 Ralph Goers <[hidden email]>:

> These are separate JVMs, so having a single executor would be of no help.
>
> I believe the only way to do what you are asking for is to add
> configuration so that the asynchronous thread has a semi-random delay when
> it starts.
>
> Ralph
>
> > On Mar 22, 2017, at 7:58 AM, Greg Thomas <[hidden email]>
> wrote:
> >
> >> One common issue we have with that framework (and I assume we can have
> the
> >> same with log4j2) is that all of our JVMs (we can have more than 50
> JVMs on
> >> the same server in production) roll their file at midnight.
> >>
> >> When this happens, the system became often not usable for a few seconds
> >> because of the simultaneous zipping of all the rolled files that
> overload
> >> the CPU (although zipping is done in a specific background thread).
> >
> > ISTR that with the most recent versions of log4j, these threads are in a
> > thread pool so that they are properly shutdown at the right time. I
> wonder
> > if it's possible (or could be possible) to somehow inject a thread pool
> in
> > to log4j for this rollover, so that for you use case you could inject a
> > single thread executor, so only one thread is ever compressing at a time.
> >
> > Just a thought, anyway,
> >
> > Greg
> >
> > On 22 March 2017 at 13:47, Anthony Maire <[hidden email]>
> wrote:
> >
> >> Hi
> >>
> >> We are currently using another logging framework in production, but I'm
> >> pushing to change it for log4j2.
> >>
> >> One common issue we have with that framework (and I assume we can have
> the
> >> same with log4j2) is that all of our JVMs (we can have more than 50
> JVMs on
> >> the same server in production) roll their file at midnight.
> >>
> >> When this happens, the system became often not usable for a few seconds
> >> because of the simultaneous zipping of all the rolled files that
> overload
> >> the CPU (although zipping is done in a specific background thread). To
> >> reduce this effect, we are combining a time based rolling policy with a
> >> sized based policy to zip smaller files, but this is not enough to make
> the
> >> system fully responsive at midnight.
> >>
> >> A pretty cool feature for us to avoid this issue is to have the
> possibility
> >> when a rolling is triggered because of a time based policy to change
> file
> >> immediately, but to wait for a random amount of time (within a
> configurable
> >> limit) before starting the compression. This random delay should help a
> lot
> >> to avoid contention on CPU cycles.
> >>
> >> Does log4j2 have something to solve this kind of issue ? If not, would
> you
> >> accept a pull request for this (I will open a Jira if needed) ?
> >>
> >> Regards,
> >> Anthony
> >>
>
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: [hidden email]
> For additional commands, e-mail: [hidden email]
>
>
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Compression of rolled files : performance issue when lots of JVMs are using timed based policy

Remko Popma-2

> On Mar 23, 2017, at 1:06, Anthony Maire <[hidden email]> wrote:
>
> Thanks for these answers
>
> @Ralph : that was the kind of idea I had in mind : changing the
> RollingFileManager.asyncExecutor to be a ScheduledThreadPoolExecutor, and
> based on some configuration, submitting task to be executed after a random
> delay. However with this kind of approach, special treatment should be made
> if the manager is stopped with some pending delayed tasks in it.

I'm okay with randomization except for this last bit about "special treatment...". Let's not make it too fancy. If the manager is stopped before it rolled over, then it didn't roll over, just like it works currently. I don't see the point of adding extra logic to trigger a rollover when the manager is stopped within the randomized time window.

>
> @Matt : Cron policy can be a solution, but I don't know how to inject some
> random element in this to make the file roll at midnight + X random
> seconds. Since there is a lot of JVM to manage and some of them can be
> moved from a machine to another, I need to have a single log4j2.xml file
> for all environments. Moreover, our system administrators are reluctant to
> have something based on a shell-specific feature (such has the $RANDOM
> variable from bash)
>
> Anthony
>
> 2017-03-22 16:31 GMT+01:00 Ralph Goers <[hidden email]>:
>
>> These are separate JVMs, so having a single executor would be of no help.
>>
>> I believe the only way to do what you are asking for is to add
>> configuration so that the asynchronous thread has a semi-random delay when
>> it starts.
>>
>> Ralph
>>
>>> On Mar 22, 2017, at 7:58 AM, Greg Thomas <[hidden email]>
>> wrote:
>>>
>>>> One common issue we have with that framework (and I assume we can have
>> the
>>>> same with log4j2) is that all of our JVMs (we can have more than 50
>> JVMs on
>>>> the same server in production) roll their file at midnight.
>>>>
>>>> When this happens, the system became often not usable for a few seconds
>>>> because of the simultaneous zipping of all the rolled files that
>> overload
>>>> the CPU (although zipping is done in a specific background thread).
>>>
>>> ISTR that with the most recent versions of log4j, these threads are in a
>>> thread pool so that they are properly shutdown at the right time. I
>> wonder
>>> if it's possible (or could be possible) to somehow inject a thread pool
>> in
>>> to log4j for this rollover, so that for you use case you could inject a
>>> single thread executor, so only one thread is ever compressing at a time.
>>>
>>> Just a thought, anyway,
>>>
>>> Greg
>>>
>>> On 22 March 2017 at 13:47, Anthony Maire <[hidden email]>
>> wrote:
>>>
>>>> Hi
>>>>
>>>> We are currently using another logging framework in production, but I'm
>>>> pushing to change it for log4j2.
>>>>
>>>> One common issue we have with that framework (and I assume we can have
>> the
>>>> same with log4j2) is that all of our JVMs (we can have more than 50
>> JVMs on
>>>> the same server in production) roll their file at midnight.
>>>>
>>>> When this happens, the system became often not usable for a few seconds
>>>> because of the simultaneous zipping of all the rolled files that
>> overload
>>>> the CPU (although zipping is done in a specific background thread). To
>>>> reduce this effect, we are combining a time based rolling policy with a
>>>> sized based policy to zip smaller files, but this is not enough to make
>> the
>>>> system fully responsive at midnight.
>>>>
>>>> A pretty cool feature for us to avoid this issue is to have the
>> possibility
>>>> when a rolling is triggered because of a time based policy to change
>> file
>>>> immediately, but to wait for a random amount of time (within a
>> configurable
>>>> limit) before starting the compression. This random delay should help a
>> lot
>>>> to avoid contention on CPU cycles.
>>>>
>>>> Does log4j2 have something to solve this kind of issue ? If not, would
>> you
>>>> accept a pull request for this (I will open a Jira if needed) ?
>>>>
>>>> Regards,
>>>> Anthony
>>>>
>>
>>
>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: [hidden email]
>> For additional commands, e-mail: [hidden email]
>>
>>

---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Compression of rolled files : performance issue when lots of JVMs are using timed based policy

Anthony Maire
Hi Remko

My first idea was to have the rolling that triggers at the expected time,
and the compression that will be delayed. That's why I wanted the delayed
compression to occur before shutdown since the rolling already occurred.

But I think that's a bad idea. First, it will lead to "fancy code" and I
would like to avoid it too. But the main issue is that this behavior should
impact only the time based triggering when combining several policy. So the
code should be related to the triggering policy and not to the rolling
strategy.

So the best thing to do is to add some property on the timed base
triggering policy and let that class handle all the logic and delay the
triggering itself instead of the compression.

Are you OK with that?

Anthony

Le 23 mars 2017 00:24, "Remko Popma" <[hidden email]> a écrit :


> On Mar 23, 2017, at 1:06, Anthony Maire <[hidden email]> wrote:
>
> Thanks for these answers
>
> @Ralph : that was the kind of idea I had in mind : changing the
> RollingFileManager.asyncExecutor to be a ScheduledThreadPoolExecutor, and
> based on some configuration, submitting task to be executed after a random
> delay. However with this kind of approach, special treatment should be
made
> if the manager is stopped with some pending delayed tasks in it.

I'm okay with randomization except for this last bit about "special
treatment...". Let's not make it too fancy. If the manager is stopped
before it rolled over, then it didn't roll over, just like it works
currently. I don't see the point of adding extra logic to trigger a
rollover when the manager is stopped within the randomized time window.

>
> @Matt : Cron policy can be a solution, but I don't know how to inject some
> random element in this to make the file roll at midnight + X random
> seconds. Since there is a lot of JVM to manage and some of them can be
> moved from a machine to another, I need to have a single log4j2.xml file
> for all environments. Moreover, our system administrators are reluctant to
> have something based on a shell-specific feature (such has the $RANDOM
> variable from bash)
>
> Anthony
>
> 2017-03-22 16:31 GMT+01:00 Ralph Goers <[hidden email]>:
>
>> These are separate JVMs, so having a single executor would be of no help.
>>
>> I believe the only way to do what you are asking for is to add
>> configuration so that the asynchronous thread has a semi-random delay
when

>> it starts.
>>
>> Ralph
>>
>>> On Mar 22, 2017, at 7:58 AM, Greg Thomas <[hidden email]>
>> wrote:
>>>
>>>> One common issue we have with that framework (and I assume we can have
>> the
>>>> same with log4j2) is that all of our JVMs (we can have more than 50
>> JVMs on
>>>> the same server in production) roll their file at midnight.
>>>>
>>>> When this happens, the system became often not usable for a few seconds
>>>> because of the simultaneous zipping of all the rolled files that
>> overload
>>>> the CPU (although zipping is done in a specific background thread).
>>>
>>> ISTR that with the most recent versions of log4j, these threads are in a
>>> thread pool so that they are properly shutdown at the right time. I
>> wonder
>>> if it's possible (or could be possible) to somehow inject a thread pool
>> in
>>> to log4j for this rollover, so that for you use case you could inject a
>>> single thread executor, so only one thread is ever compressing at a
time.

>>>
>>> Just a thought, anyway,
>>>
>>> Greg
>>>
>>> On 22 March 2017 at 13:47, Anthony Maire <[hidden email]>
>> wrote:
>>>
>>>> Hi
>>>>
>>>> We are currently using another logging framework in production, but I'm
>>>> pushing to change it for log4j2.
>>>>
>>>> One common issue we have with that framework (and I assume we can have
>> the
>>>> same with log4j2) is that all of our JVMs (we can have more than 50
>> JVMs on
>>>> the same server in production) roll their file at midnight.
>>>>
>>>> When this happens, the system became often not usable for a few seconds
>>>> because of the simultaneous zipping of all the rolled files that
>> overload
>>>> the CPU (although zipping is done in a specific background thread). To
>>>> reduce this effect, we are combining a time based rolling policy with a
>>>> sized based policy to zip smaller files, but this is not enough to make
>> the
>>>> system fully responsive at midnight.
>>>>
>>>> A pretty cool feature for us to avoid this issue is to have the
>> possibility
>>>> when a rolling is triggered because of a time based policy to change
>> file
>>>> immediately, but to wait for a random amount of time (within a
>> configurable
>>>> limit) before starting the compression. This random delay should help a
>> lot
>>>> to avoid contention on CPU cycles.
>>>>
>>>> Does log4j2 have something to solve this kind of issue ? If not, would
>> you
>>>> accept a pull request for this (I will open a Jira if needed) ?
>>>>
>>>> Regards,
>>>> Anthony
>>>>
>>
>>
>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: [hidden email]
>> For additional commands, e-mail: [hidden email]
>>
>>

---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Compression of rolled files : performance issue when lots of JVMs are using timed based policy

Remko Popma-2
I see what you mean now. I agree it's better to keep the rollover concept to mean file rename and compression that happen in sequence together. So the randomization affects when the _sequence_ is triggered, not just one part of the sequence. Makes sense.

Sent from my iPhone

> On Mar 23, 2017, at 16:28, Anthony Maire <[hidden email]> wrote:
>
> Hi Remko
>
> My first idea was to have the rolling that triggers at the expected time,
> and the compression that will be delayed. That's why I wanted the delayed
> compression to occur before shutdown since the rolling already occurred.
>
> But I think that's a bad idea. First, it will lead to "fancy code" and I
> would like to avoid it too. But the main issue is that this behavior should
> impact only the time based triggering when combining several policy. So the
> code should be related to the triggering policy and not to the rolling
> strategy.
>
> So the best thing to do is to add some property on the timed base
> triggering policy and let that class handle all the logic and delay the
> triggering itself instead of the compression.
>
> Are you OK with that?
>
> Anthony
>
> Le 23 mars 2017 00:24, "Remko Popma" <[hidden email]> a écrit :
>
>
>> On Mar 23, 2017, at 1:06, Anthony Maire <[hidden email]> wrote:
>>
>> Thanks for these answers
>>
>> @Ralph : that was the kind of idea I had in mind : changing the
>> RollingFileManager.asyncExecutor to be a ScheduledThreadPoolExecutor, and
>> based on some configuration, submitting task to be executed after a random
>> delay. However with this kind of approach, special treatment should be
> made
>> if the manager is stopped with some pending delayed tasks in it.
>
> I'm okay with randomization except for this last bit about "special
> treatment...". Let's not make it too fancy. If the manager is stopped
> before it rolled over, then it didn't roll over, just like it works
> currently. I don't see the point of adding extra logic to trigger a
> rollover when the manager is stopped within the randomized time window.
>
>>
>> @Matt : Cron policy can be a solution, but I don't know how to inject some
>> random element in this to make the file roll at midnight + X random
>> seconds. Since there is a lot of JVM to manage and some of them can be
>> moved from a machine to another, I need to have a single log4j2.xml file
>> for all environments. Moreover, our system administrators are reluctant to
>> have something based on a shell-specific feature (such has the $RANDOM
>> variable from bash)
>>
>> Anthony
>>
>> 2017-03-22 16:31 GMT+01:00 Ralph Goers <[hidden email]>:
>>
>>> These are separate JVMs, so having a single executor would be of no help.
>>>
>>> I believe the only way to do what you are asking for is to add
>>> configuration so that the asynchronous thread has a semi-random delay
> when
>>> it starts.
>>>
>>> Ralph
>>>
>>>> On Mar 22, 2017, at 7:58 AM, Greg Thomas <[hidden email]>
>>> wrote:
>>>>
>>>>> One common issue we have with that framework (and I assume we can have
>>> the
>>>>> same with log4j2) is that all of our JVMs (we can have more than 50
>>> JVMs on
>>>>> the same server in production) roll their file at midnight.
>>>>>
>>>>> When this happens, the system became often not usable for a few seconds
>>>>> because of the simultaneous zipping of all the rolled files that
>>> overload
>>>>> the CPU (although zipping is done in a specific background thread).
>>>>
>>>> ISTR that with the most recent versions of log4j, these threads are in a
>>>> thread pool so that they are properly shutdown at the right time. I
>>> wonder
>>>> if it's possible (or could be possible) to somehow inject a thread pool
>>> in
>>>> to log4j for this rollover, so that for you use case you could inject a
>>>> single thread executor, so only one thread is ever compressing at a
> time.
>>>>
>>>> Just a thought, anyway,
>>>>
>>>> Greg
>>>>
>>>> On 22 March 2017 at 13:47, Anthony Maire <[hidden email]>
>>> wrote:
>>>>
>>>>> Hi
>>>>>
>>>>> We are currently using another logging framework in production, but I'm
>>>>> pushing to change it for log4j2.
>>>>>
>>>>> One common issue we have with that framework (and I assume we can have
>>> the
>>>>> same with log4j2) is that all of our JVMs (we can have more than 50
>>> JVMs on
>>>>> the same server in production) roll their file at midnight.
>>>>>
>>>>> When this happens, the system became often not usable for a few seconds
>>>>> because of the simultaneous zipping of all the rolled files that
>>> overload
>>>>> the CPU (although zipping is done in a specific background thread). To
>>>>> reduce this effect, we are combining a time based rolling policy with a
>>>>> sized based policy to zip smaller files, but this is not enough to make
>>> the
>>>>> system fully responsive at midnight.
>>>>>
>>>>> A pretty cool feature for us to avoid this issue is to have the
>>> possibility
>>>>> when a rolling is triggered because of a time based policy to change
>>> file
>>>>> immediately, but to wait for a random amount of time (within a
>>> configurable
>>>>> limit) before starting the compression. This random delay should help a
>>> lot
>>>>> to avoid contention on CPU cycles.
>>>>>
>>>>> Does log4j2 have something to solve this kind of issue ? If not, would
>>> you
>>>>> accept a pull request for this (I will open a Jira if needed) ?
>>>>>
>>>>> Regards,
>>>>> Anthony
>>>>>
>>>
>>>
>>>
>>> ---------------------------------------------------------------------
>>> To unsubscribe, e-mail: [hidden email]
>>> For additional commands, e-mail: [hidden email]
>>>
>>>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: [hidden email]
> For additional commands, e-mail: [hidden email]

---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Compression of rolled files : performance issue when lots of JVMs are using timed based policy

Anthony Maire
Ok,  I will open a jira ticket and provide a PR.

Thanks for your input.

Le 23 mars 2017 13:08, "Remko Popma" <[hidden email]> a écrit :

> I see what you mean now. I agree it's better to keep the rollover concept
> to mean file rename and compression that happen in sequence together. So
> the randomization affects when the _sequence_ is triggered, not just one
> part of the sequence. Makes sense.
>
> Sent from my iPhone
>
> > On Mar 23, 2017, at 16:28, Anthony Maire <[hidden email]>
> wrote:
> >
> > Hi Remko
> >
> > My first idea was to have the rolling that triggers at the expected time,
> > and the compression that will be delayed. That's why I wanted the delayed
> > compression to occur before shutdown since the rolling already occurred.
> >
> > But I think that's a bad idea. First, it will lead to "fancy code" and I
> > would like to avoid it too. But the main issue is that this behavior
> should
> > impact only the time based triggering when combining several policy. So
> the
> > code should be related to the triggering policy and not to the rolling
> > strategy.
> >
> > So the best thing to do is to add some property on the timed base
> > triggering policy and let that class handle all the logic and delay the
> > triggering itself instead of the compression.
> >
> > Are you OK with that?
> >
> > Anthony
> >
> > Le 23 mars 2017 00:24, "Remko Popma" <[hidden email]> a écrit :
> >
> >
> >> On Mar 23, 2017, at 1:06, Anthony Maire <[hidden email]>
> wrote:
> >>
> >> Thanks for these answers
> >>
> >> @Ralph : that was the kind of idea I had in mind : changing the
> >> RollingFileManager.asyncExecutor to be a ScheduledThreadPoolExecutor,
> and
> >> based on some configuration, submitting task to be executed after a
> random
> >> delay. However with this kind of approach, special treatment should be
> > made
> >> if the manager is stopped with some pending delayed tasks in it.
> >
> > I'm okay with randomization except for this last bit about "special
> > treatment...". Let's not make it too fancy. If the manager is stopped
> > before it rolled over, then it didn't roll over, just like it works
> > currently. I don't see the point of adding extra logic to trigger a
> > rollover when the manager is stopped within the randomized time window.
> >
> >>
> >> @Matt : Cron policy can be a solution, but I don't know how to inject
> some
> >> random element in this to make the file roll at midnight + X random
> >> seconds. Since there is a lot of JVM to manage and some of them can be
> >> moved from a machine to another, I need to have a single log4j2.xml file
> >> for all environments. Moreover, our system administrators are reluctant
> to
> >> have something based on a shell-specific feature (such has the $RANDOM
> >> variable from bash)
> >>
> >> Anthony
> >>
> >> 2017-03-22 16:31 GMT+01:00 Ralph Goers <[hidden email]>:
> >>
> >>> These are separate JVMs, so having a single executor would be of no
> help.
> >>>
> >>> I believe the only way to do what you are asking for is to add
> >>> configuration so that the asynchronous thread has a semi-random delay
> > when
> >>> it starts.
> >>>
> >>> Ralph
> >>>
> >>>> On Mar 22, 2017, at 7:58 AM, Greg Thomas <[hidden email]>
> >>> wrote:
> >>>>
> >>>>> One common issue we have with that framework (and I assume we can
> have
> >>> the
> >>>>> same with log4j2) is that all of our JVMs (we can have more than 50
> >>> JVMs on
> >>>>> the same server in production) roll their file at midnight.
> >>>>>
> >>>>> When this happens, the system became often not usable for a few
> seconds
> >>>>> because of the simultaneous zipping of all the rolled files that
> >>> overload
> >>>>> the CPU (although zipping is done in a specific background thread).
> >>>>
> >>>> ISTR that with the most recent versions of log4j, these threads are
> in a
> >>>> thread pool so that they are properly shutdown at the right time. I
> >>> wonder
> >>>> if it's possible (or could be possible) to somehow inject a thread
> pool
> >>> in
> >>>> to log4j for this rollover, so that for you use case you could inject
> a
> >>>> single thread executor, so only one thread is ever compressing at a
> > time.
> >>>>
> >>>> Just a thought, anyway,
> >>>>
> >>>> Greg
> >>>>
> >>>> On 22 March 2017 at 13:47, Anthony Maire <[hidden email]>
> >>> wrote:
> >>>>
> >>>>> Hi
> >>>>>
> >>>>> We are currently using another logging framework in production, but
> I'm
> >>>>> pushing to change it for log4j2.
> >>>>>
> >>>>> One common issue we have with that framework (and I assume we can
> have
> >>> the
> >>>>> same with log4j2) is that all of our JVMs (we can have more than 50
> >>> JVMs on
> >>>>> the same server in production) roll their file at midnight.
> >>>>>
> >>>>> When this happens, the system became often not usable for a few
> seconds
> >>>>> because of the simultaneous zipping of all the rolled files that
> >>> overload
> >>>>> the CPU (although zipping is done in a specific background thread).
> To
> >>>>> reduce this effect, we are combining a time based rolling policy
> with a
> >>>>> sized based policy to zip smaller files, but this is not enough to
> make
> >>> the
> >>>>> system fully responsive at midnight.
> >>>>>
> >>>>> A pretty cool feature for us to avoid this issue is to have the
> >>> possibility
> >>>>> when a rolling is triggered because of a time based policy to change
> >>> file
> >>>>> immediately, but to wait for a random amount of time (within a
> >>> configurable
> >>>>> limit) before starting the compression. This random delay should
> help a
> >>> lot
> >>>>> to avoid contention on CPU cycles.
> >>>>>
> >>>>> Does log4j2 have something to solve this kind of issue ? If not,
> would
> >>> you
> >>>>> accept a pull request for this (I will open a Jira if needed) ?
> >>>>>
> >>>>> Regards,
> >>>>> Anthony
> >>>>>
> >>>
> >>>
> >>>
> >>> ---------------------------------------------------------------------
> >>> To unsubscribe, e-mail: [hidden email]
> >>> For additional commands, e-mail: [hidden email]
> >>>
> >>>
> >
> > ---------------------------------------------------------------------
> > To unsubscribe, e-mail: [hidden email]
> > For additional commands, e-mail: [hidden email]
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: [hidden email]
> For additional commands, e-mail: [hidden email]
>
>
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Compression of rolled files : performance issue when lots of JVMs are using timed based policy

Anthony Maire
https://issues.apache.org/jira/browse/LOG4J2-1855
https://github.com/apache/logging-log4j2/pull/68

Let me know if you want me to do some changes

Regards,
Anthony


2017-03-23 13:15 GMT+01:00 Anthony Maire <[hidden email]>:

> Ok,  I will open a jira ticket and provide a PR.
>
> Thanks for your input.
>
> Le 23 mars 2017 13:08, "Remko Popma" <[hidden email]> a écrit :
>
>> I see what you mean now. I agree it's better to keep the rollover concept
>> to mean file rename and compression that happen in sequence together. So
>> the randomization affects when the _sequence_ is triggered, not just one
>> part of the sequence. Makes sense.
>>
>> Sent from my iPhone
>>
>> > On Mar 23, 2017, at 16:28, Anthony Maire <[hidden email]>
>> wrote:
>> >
>> > Hi Remko
>> >
>> > My first idea was to have the rolling that triggers at the expected
>> time,
>> > and the compression that will be delayed. That's why I wanted the
>> delayed
>> > compression to occur before shutdown since the rolling already occurred.
>> >
>> > But I think that's a bad idea. First, it will lead to "fancy code" and I
>> > would like to avoid it too. But the main issue is that this behavior
>> should
>> > impact only the time based triggering when combining several policy. So
>> the
>> > code should be related to the triggering policy and not to the rolling
>> > strategy.
>> >
>> > So the best thing to do is to add some property on the timed base
>> > triggering policy and let that class handle all the logic and delay the
>> > triggering itself instead of the compression.
>> >
>> > Are you OK with that?
>> >
>> > Anthony
>> >
>> > Le 23 mars 2017 00:24, "Remko Popma" <[hidden email]> a écrit :
>> >
>> >
>> >> On Mar 23, 2017, at 1:06, Anthony Maire <[hidden email]>
>> wrote:
>> >>
>> >> Thanks for these answers
>> >>
>> >> @Ralph : that was the kind of idea I had in mind : changing the
>> >> RollingFileManager.asyncExecutor to be a ScheduledThreadPoolExecutor,
>> and
>> >> based on some configuration, submitting task to be executed after a
>> random
>> >> delay. However with this kind of approach, special treatment should be
>> > made
>> >> if the manager is stopped with some pending delayed tasks in it.
>> >
>> > I'm okay with randomization except for this last bit about "special
>> > treatment...". Let's not make it too fancy. If the manager is stopped
>> > before it rolled over, then it didn't roll over, just like it works
>> > currently. I don't see the point of adding extra logic to trigger a
>> > rollover when the manager is stopped within the randomized time window.
>> >
>> >>
>> >> @Matt : Cron policy can be a solution, but I don't know how to inject
>> some
>> >> random element in this to make the file roll at midnight + X random
>> >> seconds. Since there is a lot of JVM to manage and some of them can be
>> >> moved from a machine to another, I need to have a single log4j2.xml
>> file
>> >> for all environments. Moreover, our system administrators are
>> reluctant to
>> >> have something based on a shell-specific feature (such has the $RANDOM
>> >> variable from bash)
>> >>
>> >> Anthony
>> >>
>> >> 2017-03-22 16:31 GMT+01:00 Ralph Goers <[hidden email]>:
>> >>
>> >>> These are separate JVMs, so having a single executor would be of no
>> help.
>> >>>
>> >>> I believe the only way to do what you are asking for is to add
>> >>> configuration so that the asynchronous thread has a semi-random delay
>> > when
>> >>> it starts.
>> >>>
>> >>> Ralph
>> >>>
>> >>>> On Mar 22, 2017, at 7:58 AM, Greg Thomas <[hidden email]>
>> >>> wrote:
>> >>>>
>> >>>>> One common issue we have with that framework (and I assume we can
>> have
>> >>> the
>> >>>>> same with log4j2) is that all of our JVMs (we can have more than 50
>> >>> JVMs on
>> >>>>> the same server in production) roll their file at midnight.
>> >>>>>
>> >>>>> When this happens, the system became often not usable for a few
>> seconds
>> >>>>> because of the simultaneous zipping of all the rolled files that
>> >>> overload
>> >>>>> the CPU (although zipping is done in a specific background thread).
>> >>>>
>> >>>> ISTR that with the most recent versions of log4j, these threads are
>> in a
>> >>>> thread pool so that they are properly shutdown at the right time. I
>> >>> wonder
>> >>>> if it's possible (or could be possible) to somehow inject a thread
>> pool
>> >>> in
>> >>>> to log4j for this rollover, so that for you use case you could
>> inject a
>> >>>> single thread executor, so only one thread is ever compressing at a
>> > time.
>> >>>>
>> >>>> Just a thought, anyway,
>> >>>>
>> >>>> Greg
>> >>>>
>> >>>> On 22 March 2017 at 13:47, Anthony Maire <[hidden email]>
>> >>> wrote:
>> >>>>
>> >>>>> Hi
>> >>>>>
>> >>>>> We are currently using another logging framework in production, but
>> I'm
>> >>>>> pushing to change it for log4j2.
>> >>>>>
>> >>>>> One common issue we have with that framework (and I assume we can
>> have
>> >>> the
>> >>>>> same with log4j2) is that all of our JVMs (we can have more than 50
>> >>> JVMs on
>> >>>>> the same server in production) roll their file at midnight.
>> >>>>>
>> >>>>> When this happens, the system became often not usable for a few
>> seconds
>> >>>>> because of the simultaneous zipping of all the rolled files that
>> >>> overload
>> >>>>> the CPU (although zipping is done in a specific background thread).
>> To
>> >>>>> reduce this effect, we are combining a time based rolling policy
>> with a
>> >>>>> sized based policy to zip smaller files, but this is not enough to
>> make
>> >>> the
>> >>>>> system fully responsive at midnight.
>> >>>>>
>> >>>>> A pretty cool feature for us to avoid this issue is to have the
>> >>> possibility
>> >>>>> when a rolling is triggered because of a time based policy to change
>> >>> file
>> >>>>> immediately, but to wait for a random amount of time (within a
>> >>> configurable
>> >>>>> limit) before starting the compression. This random delay should
>> help a
>> >>> lot
>> >>>>> to avoid contention on CPU cycles.
>> >>>>>
>> >>>>> Does log4j2 have something to solve this kind of issue ? If not,
>> would
>> >>> you
>> >>>>> accept a pull request for this (I will open a Jira if needed) ?
>> >>>>>
>> >>>>> Regards,
>> >>>>> Anthony
>> >>>>>
>> >>>
>> >>>
>> >>>
>> >>> ---------------------------------------------------------------------
>> >>> To unsubscribe, e-mail: [hidden email]
>> >>> For additional commands, e-mail: [hidden email]
>> >>>
>> >>>
>> >
>> > ---------------------------------------------------------------------
>> > To unsubscribe, e-mail: [hidden email]
>> > For additional commands, e-mail: [hidden email]
>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: [hidden email]
>> For additional commands, e-mail: [hidden email]
>>
>>
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Compression of rolled files : performance issue when lots of JVMs are using timed based policy

Dominik Psenner-2
Hi there,

Cron proved itself very to be stable and usable over the past years.
FWIW, I would not recommend to introduce a randomization algorithm. An
application that does things random means that the application does
things when nobody expects it to do so. Further it does not solve the
problem. One just needs enough JVMs to roll around at the same time with
a randomizer does not produce large enough values to spread the rolling
over a larger amount of time. The available CPU is then quickly drain
out. In my opinion, it's better to configure the several rollings to be
delayed, meaning that JVM1 rolls at 12:00, JVM2 rolls at 12:01, ...

Cheers, Dominik

On 2017-03-23 15:04, Anthony Maire wrote:

> https://issues.apache.org/jira/browse/LOG4J2-1855
> https://github.com/apache/logging-log4j2/pull/68
>
> Let me know if you want me to do some changes
>
> Regards,
> Anthony
>
>
> 2017-03-23 13:15 GMT+01:00 Anthony Maire <[hidden email]>:
>
>> Ok,  I will open a jira ticket and provide a PR.
>>
>> Thanks for your input.
>>
>> Le 23 mars 2017 13:08, "Remko Popma" <[hidden email]> a écrit :
>>
>>> I see what you mean now. I agree it's better to keep the rollover concept
>>> to mean file rename and compression that happen in sequence together. So
>>> the randomization affects when the _sequence_ is triggered, not just one
>>> part of the sequence. Makes sense.
>>>
>>> Sent from my iPhone
>>>
>>>> On Mar 23, 2017, at 16:28, Anthony Maire <[hidden email]>
>>> wrote:
>>>> Hi Remko
>>>>
>>>> My first idea was to have the rolling that triggers at the expected
>>> time,
>>>> and the compression that will be delayed. That's why I wanted the
>>> delayed
>>>> compression to occur before shutdown since the rolling already occurred.
>>>>
>>>> But I think that's a bad idea. First, it will lead to "fancy code" and I
>>>> would like to avoid it too. But the main issue is that this behavior
>>> should
>>>> impact only the time based triggering when combining several policy. So
>>> the
>>>> code should be related to the triggering policy and not to the rolling
>>>> strategy.
>>>>
>>>> So the best thing to do is to add some property on the timed base
>>>> triggering policy and let that class handle all the logic and delay the
>>>> triggering itself instead of the compression.
>>>>
>>>> Are you OK with that?
>>>>
>>>> Anthony
>>>>
>>>> Le 23 mars 2017 00:24, "Remko Popma" <[hidden email]> a écrit :
>>>>
>>>>
>>>>> On Mar 23, 2017, at 1:06, Anthony Maire <[hidden email]>
>>> wrote:
>>>>> Thanks for these answers
>>>>>
>>>>> @Ralph : that was the kind of idea I had in mind : changing the
>>>>> RollingFileManager.asyncExecutor to be a ScheduledThreadPoolExecutor,
>>> and
>>>>> based on some configuration, submitting task to be executed after a
>>> random
>>>>> delay. However with this kind of approach, special treatment should be
>>>> made
>>>>> if the manager is stopped with some pending delayed tasks in it.
>>>> I'm okay with randomization except for this last bit about "special
>>>> treatment...". Let's not make it too fancy. If the manager is stopped
>>>> before it rolled over, then it didn't roll over, just like it works
>>>> currently. I don't see the point of adding extra logic to trigger a
>>>> rollover when the manager is stopped within the randomized time window.
>>>>
>>>>> @Matt : Cron policy can be a solution, but I don't know how to inject
>>> some
>>>>> random element in this to make the file roll at midnight + X random
>>>>> seconds. Since there is a lot of JVM to manage and some of them can be
>>>>> moved from a machine to another, I need to have a single log4j2.xml
>>> file
>>>>> for all environments. Moreover, our system administrators are
>>> reluctant to
>>>>> have something based on a shell-specific feature (such has the $RANDOM
>>>>> variable from bash)
>>>>>
>>>>> Anthony
>>>>>
>>>>> 2017-03-22 16:31 GMT+01:00 Ralph Goers <[hidden email]>:
>>>>>
>>>>>> These are separate JVMs, so having a single executor would be of no
>>> help.
>>>>>> I believe the only way to do what you are asking for is to add
>>>>>> configuration so that the asynchronous thread has a semi-random delay
>>>> when
>>>>>> it starts.
>>>>>>
>>>>>> Ralph
>>>>>>
>>>>>>> On Mar 22, 2017, at 7:58 AM, Greg Thomas <[hidden email]>
>>>>>> wrote:
>>>>>>>> One common issue we have with that framework (and I assume we can
>>> have
>>>>>> the
>>>>>>>> same with log4j2) is that all of our JVMs (we can have more than 50
>>>>>> JVMs on
>>>>>>>> the same server in production) roll their file at midnight.
>>>>>>>>
>>>>>>>> When this happens, the system became often not usable for a few
>>> seconds
>>>>>>>> because of the simultaneous zipping of all the rolled files that
>>>>>> overload
>>>>>>>> the CPU (although zipping is done in a specific background thread).
>>>>>>> ISTR that with the most recent versions of log4j, these threads are
>>> in a
>>>>>>> thread pool so that they are properly shutdown at the right time. I
>>>>>> wonder
>>>>>>> if it's possible (or could be possible) to somehow inject a thread
>>> pool
>>>>>> in
>>>>>>> to log4j for this rollover, so that for you use case you could
>>> inject a
>>>>>>> single thread executor, so only one thread is ever compressing at a
>>>> time.
>>>>>>> Just a thought, anyway,
>>>>>>>
>>>>>>> Greg
>>>>>>>
>>>>>>> On 22 March 2017 at 13:47, Anthony Maire <[hidden email]>
>>>>>> wrote:
>>>>>>>> Hi
>>>>>>>>
>>>>>>>> We are currently using another logging framework in production, but
>>> I'm
>>>>>>>> pushing to change it for log4j2.
>>>>>>>>
>>>>>>>> One common issue we have with that framework (and I assume we can
>>> have
>>>>>> the
>>>>>>>> same with log4j2) is that all of our JVMs (we can have more than 50
>>>>>> JVMs on
>>>>>>>> the same server in production) roll their file at midnight.
>>>>>>>>
>>>>>>>> When this happens, the system became often not usable for a few
>>> seconds
>>>>>>>> because of the simultaneous zipping of all the rolled files that
>>>>>> overload
>>>>>>>> the CPU (although zipping is done in a specific background thread).
>>> To
>>>>>>>> reduce this effect, we are combining a time based rolling policy
>>> with a
>>>>>>>> sized based policy to zip smaller files, but this is not enough to
>>> make
>>>>>> the
>>>>>>>> system fully responsive at midnight.
>>>>>>>>
>>>>>>>> A pretty cool feature for us to avoid this issue is to have the
>>>>>> possibility
>>>>>>>> when a rolling is triggered because of a time based policy to change
>>>>>> file
>>>>>>>> immediately, but to wait for a random amount of time (within a
>>>>>> configurable
>>>>>>>> limit) before starting the compression. This random delay should
>>> help a
>>>>>> lot
>>>>>>>> to avoid contention on CPU cycles.
>>>>>>>>
>>>>>>>> Does log4j2 have something to solve this kind of issue ? If not,
>>> would
>>>>>> you
>>>>>>>> accept a pull request for this (I will open a Jira if needed) ?
>>>>>>>>
>>>>>>>> Regards,
>>>>>>>> Anthony
>>>>>>>>
>>>>>>
>>>>>>
>>>>>> ---------------------------------------------------------------------
>>>>>> To unsubscribe, e-mail: [hidden email]
>>>>>> For additional commands, e-mail: [hidden email]
>>>>>>
>>>>>>
>>>> ---------------------------------------------------------------------
>>>> To unsubscribe, e-mail: [hidden email]
>>>> For additional commands, e-mail: [hidden email]
>>> ---------------------------------------------------------------------
>>> To unsubscribe, e-mail: [hidden email]
>>> For additional commands, e-mail: [hidden email]
>>>
>>>


---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Compression of rolled files : performance issue when lots of JVMs are using timed based policy

Remko Popma-2
I see what you are saying, but the use case is to have a single configuration, that is what drives the request.

Sent from my iPhone

> On Mar 24, 2017, at 17:22, Dominik Psenner <[hidden email]> wrote:
>
> Hi there,
>
> Cron proved itself very to be stable and usable over the past years. FWIW, I would not recommend to introduce a randomization algorithm. An application that does things random means that the application does things when nobody expects it to do so. Further it does not solve the problem. One just needs enough JVMs to roll around at the same time with a randomizer does not produce large enough values to spread the rolling over a larger amount of time. The available CPU is then quickly drain out. In my opinion, it's better to configure the several rollings to be delayed, meaning that JVM1 rolls at 12:00, JVM2 rolls at 12:01, ...
>
> Cheers, Dominik
>
>> On 2017-03-23 15:04, Anthony Maire wrote:
>> https://issues.apache.org/jira/browse/LOG4J2-1855
>> https://github.com/apache/logging-log4j2/pull/68
>>
>> Let me know if you want me to do some changes
>>
>> Regards,
>> Anthony
>>
>>
>> 2017-03-23 13:15 GMT+01:00 Anthony Maire <[hidden email]>:
>>
>>> Ok,  I will open a jira ticket and provide a PR.
>>>
>>> Thanks for your input.
>>>
>>> Le 23 mars 2017 13:08, "Remko Popma" <[hidden email]> a écrit :
>>>
>>>> I see what you mean now. I agree it's better to keep the rollover concept
>>>> to mean file rename and compression that happen in sequence together. So
>>>> the randomization affects when the _sequence_ is triggered, not just one
>>>> part of the sequence. Makes sense.
>>>>
>>>> Sent from my iPhone
>>>>
>>>>> On Mar 23, 2017, at 16:28, Anthony Maire <[hidden email]>
>>>> wrote:
>>>>> Hi Remko
>>>>>
>>>>> My first idea was to have the rolling that triggers at the expected
>>>> time,
>>>>> and the compression that will be delayed. That's why I wanted the
>>>> delayed
>>>>> compression to occur before shutdown since the rolling already occurred.
>>>>>
>>>>> But I think that's a bad idea. First, it will lead to "fancy code" and I
>>>>> would like to avoid it too. But the main issue is that this behavior
>>>> should
>>>>> impact only the time based triggering when combining several policy. So
>>>> the
>>>>> code should be related to the triggering policy and not to the rolling
>>>>> strategy.
>>>>>
>>>>> So the best thing to do is to add some property on the timed base
>>>>> triggering policy and let that class handle all the logic and delay the
>>>>> triggering itself instead of the compression.
>>>>>
>>>>> Are you OK with that?
>>>>>
>>>>> Anthony
>>>>>
>>>>> Le 23 mars 2017 00:24, "Remko Popma" <[hidden email]> a écrit :
>>>>>
>>>>>
>>>>>> On Mar 23, 2017, at 1:06, Anthony Maire <[hidden email]>
>>>> wrote:
>>>>>> Thanks for these answers
>>>>>>
>>>>>> @Ralph : that was the kind of idea I had in mind : changing the
>>>>>> RollingFileManager.asyncExecutor to be a ScheduledThreadPoolExecutor,
>>>> and
>>>>>> based on some configuration, submitting task to be executed after a
>>>> random
>>>>>> delay. However with this kind of approach, special treatment should be
>>>>> made
>>>>>> if the manager is stopped with some pending delayed tasks in it.
>>>>> I'm okay with randomization except for this last bit about "special
>>>>> treatment...". Let's not make it too fancy. If the manager is stopped
>>>>> before it rolled over, then it didn't roll over, just like it works
>>>>> currently. I don't see the point of adding extra logic to trigger a
>>>>> rollover when the manager is stopped within the randomized time window.
>>>>>
>>>>>> @Matt : Cron policy can be a solution, but I don't know how to inject
>>>> some
>>>>>> random element in this to make the file roll at midnight + X random
>>>>>> seconds. Since there is a lot of JVM to manage and some of them can be
>>>>>> moved from a machine to another, I need to have a single log4j2.xml
>>>> file
>>>>>> for all environments. Moreover, our system administrators are
>>>> reluctant to
>>>>>> have something based on a shell-specific feature (such has the $RANDOM
>>>>>> variable from bash)
>>>>>>
>>>>>> Anthony
>>>>>>
>>>>>> 2017-03-22 16:31 GMT+01:00 Ralph Goers <[hidden email]>:
>>>>>>
>>>>>>> These are separate JVMs, so having a single executor would be of no
>>>> help.
>>>>>>> I believe the only way to do what you are asking for is to add
>>>>>>> configuration so that the asynchronous thread has a semi-random delay
>>>>> when
>>>>>>> it starts.
>>>>>>>
>>>>>>> Ralph
>>>>>>>
>>>>>>>> On Mar 22, 2017, at 7:58 AM, Greg Thomas <[hidden email]>
>>>>>>> wrote:
>>>>>>>>> One common issue we have with that framework (and I assume we can
>>>> have
>>>>>>> the
>>>>>>>>> same with log4j2) is that all of our JVMs (we can have more than 50
>>>>>>> JVMs on
>>>>>>>>> the same server in production) roll their file at midnight.
>>>>>>>>>
>>>>>>>>> When this happens, the system became often not usable for a few
>>>> seconds
>>>>>>>>> because of the simultaneous zipping of all the rolled files that
>>>>>>> overload
>>>>>>>>> the CPU (although zipping is done in a specific background thread).
>>>>>>>> ISTR that with the most recent versions of log4j, these threads are
>>>> in a
>>>>>>>> thread pool so that they are properly shutdown at the right time. I
>>>>>>> wonder
>>>>>>>> if it's possible (or could be possible) to somehow inject a thread
>>>> pool
>>>>>>> in
>>>>>>>> to log4j for this rollover, so that for you use case you could
>>>> inject a
>>>>>>>> single thread executor, so only one thread is ever compressing at a
>>>>> time.
>>>>>>>> Just a thought, anyway,
>>>>>>>>
>>>>>>>> Greg
>>>>>>>>
>>>>>>>> On 22 March 2017 at 13:47, Anthony Maire <[hidden email]>
>>>>>>> wrote:
>>>>>>>>> Hi
>>>>>>>>>
>>>>>>>>> We are currently using another logging framework in production, but
>>>> I'm
>>>>>>>>> pushing to change it for log4j2.
>>>>>>>>>
>>>>>>>>> One common issue we have with that framework (and I assume we can
>>>> have
>>>>>>> the
>>>>>>>>> same with log4j2) is that all of our JVMs (we can have more than 50
>>>>>>> JVMs on
>>>>>>>>> the same server in production) roll their file at midnight.
>>>>>>>>>
>>>>>>>>> When this happens, the system became often not usable for a few
>>>> seconds
>>>>>>>>> because of the simultaneous zipping of all the rolled files that
>>>>>>> overload
>>>>>>>>> the CPU (although zipping is done in a specific background thread).
>>>> To
>>>>>>>>> reduce this effect, we are combining a time based rolling policy
>>>> with a
>>>>>>>>> sized based policy to zip smaller files, but this is not enough to
>>>> make
>>>>>>> the
>>>>>>>>> system fully responsive at midnight.
>>>>>>>>>
>>>>>>>>> A pretty cool feature for us to avoid this issue is to have the
>>>>>>> possibility
>>>>>>>>> when a rolling is triggered because of a time based policy to change
>>>>>>> file
>>>>>>>>> immediately, but to wait for a random amount of time (within a
>>>>>>> configurable
>>>>>>>>> limit) before starting the compression. This random delay should
>>>> help a
>>>>>>> lot
>>>>>>>>> to avoid contention on CPU cycles.
>>>>>>>>>
>>>>>>>>> Does log4j2 have something to solve this kind of issue ? If not,
>>>> would
>>>>>>> you
>>>>>>>>> accept a pull request for this (I will open a Jira if needed) ?
>>>>>>>>>
>>>>>>>>> Regards,
>>>>>>>>> Anthony
>>>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>> ---------------------------------------------------------------------
>>>>>>> To unsubscribe, e-mail: [hidden email]
>>>>>>> For additional commands, e-mail: [hidden email]
>>>>>>>
>>>>>>>
>>>>> ---------------------------------------------------------------------
>>>>> To unsubscribe, e-mail: [hidden email]
>>>>> For additional commands, e-mail: [hidden email]
>>>> ---------------------------------------------------------------------
>>>> To unsubscribe, e-mail: [hidden email]
>>>> For additional commands, e-mail: [hidden email]
>>>>
>>>>
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: [hidden email]
> For additional commands, e-mail: [hidden email]
>

---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Compression of rolled files : performance issue when lots of JVMs are using timed based policy

Dominik Psenner-2
What if a configuration could contain conditional statements? For instance:

<Config>
        <Define EnvironmentVariable="Hour" Value="12" />
        <Define EnvironmentVariable="Minute" Value="0" />
        <If EnvironmentVariable="JVM" Equals="JVM1">
                <Define EnvironmentVariable="Minute" Value="0" />
        </If>
        <If EnvironmentVariable="JVM" Equals="JVM2">
                <Define EnvironmentVariable="Minute" Value="1" />
        </If>
        <RollingFileAppender>
                <RollingCondition>
                        <Cron Minute="$Minute" Hour="$Hour" DayOfMonth="*" Month="*" DayOfWeek="*" />
                </RollingCondition>
        </RollingFileAppender>
</Config>

Cheers

On 2017-03-24 11:08, Remko Popma wrote:

> I see what you are saying, but the use case is to have a single configuration, that is what drives the request.
>
> Sent from my iPhone
>
>> On Mar 24, 2017, at 17:22, Dominik Psenner <[hidden email]> wrote:
>>
>> Hi there,
>>
>> Cron proved itself very to be stable and usable over the past years. FWIW, I would not recommend to introduce a randomization algorithm. An application that does things random means that the application does things when nobody expects it to do so. Further it does not solve the problem. One just needs enough JVMs to roll around at the same time with a randomizer does not produce large enough values to spread the rolling over a larger amount of time. The available CPU is then quickly drain out. In my opinion, it's better to configure the several rollings to be delayed, meaning that JVM1 rolls at 12:00, JVM2 rolls at 12:01, ...
>>
>> Cheers, Dominik
>>
>>> On 2017-03-23 15:04, Anthony Maire wrote:
>>> https://issues.apache.org/jira/browse/LOG4J2-1855
>>> https://github.com/apache/logging-log4j2/pull/68
>>>
>>> Let me know if you want me to do some changes
>>>
>>> Regards,
>>> Anthony
>>>
>>>
>>> 2017-03-23 13:15 GMT+01:00 Anthony Maire <[hidden email]>:
>>>
>>>> Ok,  I will open a jira ticket and provide a PR.
>>>>
>>>> Thanks for your input.
>>>>
>>>> Le 23 mars 2017 13:08, "Remko Popma" <[hidden email]> a écrit :
>>>>
>>>>> I see what you mean now. I agree it's better to keep the rollover concept
>>>>> to mean file rename and compression that happen in sequence together. So
>>>>> the randomization affects when the _sequence_ is triggered, not just one
>>>>> part of the sequence. Makes sense.
>>>>>
>>>>> Sent from my iPhone
>>>>>
>>>>>> On Mar 23, 2017, at 16:28, Anthony Maire <[hidden email]>
>>>>> wrote:
>>>>>> Hi Remko
>>>>>>
>>>>>> My first idea was to have the rolling that triggers at the expected
>>>>> time,
>>>>>> and the compression that will be delayed. That's why I wanted the
>>>>> delayed
>>>>>> compression to occur before shutdown since the rolling already occurred.
>>>>>>
>>>>>> But I think that's a bad idea. First, it will lead to "fancy code" and I
>>>>>> would like to avoid it too. But the main issue is that this behavior
>>>>> should
>>>>>> impact only the time based triggering when combining several policy. So
>>>>> the
>>>>>> code should be related to the triggering policy and not to the rolling
>>>>>> strategy.
>>>>>>
>>>>>> So the best thing to do is to add some property on the timed base
>>>>>> triggering policy and let that class handle all the logic and delay the
>>>>>> triggering itself instead of the compression.
>>>>>>
>>>>>> Are you OK with that?
>>>>>>
>>>>>> Anthony
>>>>>>
>>>>>> Le 23 mars 2017 00:24, "Remko Popma" <[hidden email]> a écrit :
>>>>>>
>>>>>>
>>>>>>> On Mar 23, 2017, at 1:06, Anthony Maire <[hidden email]>
>>>>> wrote:
>>>>>>> Thanks for these answers
>>>>>>>
>>>>>>> @Ralph : that was the kind of idea I had in mind : changing the
>>>>>>> RollingFileManager.asyncExecutor to be a ScheduledThreadPoolExecutor,
>>>>> and
>>>>>>> based on some configuration, submitting task to be executed after a
>>>>> random
>>>>>>> delay. However with this kind of approach, special treatment should be
>>>>>> made
>>>>>>> if the manager is stopped with some pending delayed tasks in it.
>>>>>> I'm okay with randomization except for this last bit about "special
>>>>>> treatment...". Let's not make it too fancy. If the manager is stopped
>>>>>> before it rolled over, then it didn't roll over, just like it works
>>>>>> currently. I don't see the point of adding extra logic to trigger a
>>>>>> rollover when the manager is stopped within the randomized time window.
>>>>>>
>>>>>>> @Matt : Cron policy can be a solution, but I don't know how to inject
>>>>> some
>>>>>>> random element in this to make the file roll at midnight + X random
>>>>>>> seconds. Since there is a lot of JVM to manage and some of them can be
>>>>>>> moved from a machine to another, I need to have a single log4j2.xml
>>>>> file
>>>>>>> for all environments. Moreover, our system administrators are
>>>>> reluctant to
>>>>>>> have something based on a shell-specific feature (such has the $RANDOM
>>>>>>> variable from bash)
>>>>>>>
>>>>>>> Anthony
>>>>>>>
>>>>>>> 2017-03-22 16:31 GMT+01:00 Ralph Goers <[hidden email]>:
>>>>>>>
>>>>>>>> These are separate JVMs, so having a single executor would be of no
>>>>> help.
>>>>>>>> I believe the only way to do what you are asking for is to add
>>>>>>>> configuration so that the asynchronous thread has a semi-random delay
>>>>>> when
>>>>>>>> it starts.
>>>>>>>>
>>>>>>>> Ralph
>>>>>>>>
>>>>>>>>> On Mar 22, 2017, at 7:58 AM, Greg Thomas <[hidden email]>
>>>>>>>> wrote:
>>>>>>>>>> One common issue we have with that framework (and I assume we can
>>>>> have
>>>>>>>> the
>>>>>>>>>> same with log4j2) is that all of our JVMs (we can have more than 50
>>>>>>>> JVMs on
>>>>>>>>>> the same server in production) roll their file at midnight.
>>>>>>>>>>
>>>>>>>>>> When this happens, the system became often not usable for a few
>>>>> seconds
>>>>>>>>>> because of the simultaneous zipping of all the rolled files that
>>>>>>>> overload
>>>>>>>>>> the CPU (although zipping is done in a specific background thread).
>>>>>>>>> ISTR that with the most recent versions of log4j, these threads are
>>>>> in a
>>>>>>>>> thread pool so that they are properly shutdown at the right time. I
>>>>>>>> wonder
>>>>>>>>> if it's possible (or could be possible) to somehow inject a thread
>>>>> pool
>>>>>>>> in
>>>>>>>>> to log4j for this rollover, so that for you use case you could
>>>>> inject a
>>>>>>>>> single thread executor, so only one thread is ever compressing at a
>>>>>> time.
>>>>>>>>> Just a thought, anyway,
>>>>>>>>>
>>>>>>>>> Greg
>>>>>>>>>
>>>>>>>>> On 22 March 2017 at 13:47, Anthony Maire <[hidden email]>
>>>>>>>> wrote:
>>>>>>>>>> Hi
>>>>>>>>>>
>>>>>>>>>> We are currently using another logging framework in production, but
>>>>> I'm
>>>>>>>>>> pushing to change it for log4j2.
>>>>>>>>>>
>>>>>>>>>> One common issue we have with that framework (and I assume we can
>>>>> have
>>>>>>>> the
>>>>>>>>>> same with log4j2) is that all of our JVMs (we can have more than 50
>>>>>>>> JVMs on
>>>>>>>>>> the same server in production) roll their file at midnight.
>>>>>>>>>>
>>>>>>>>>> When this happens, the system became often not usable for a few
>>>>> seconds
>>>>>>>>>> because of the simultaneous zipping of all the rolled files that
>>>>>>>> overload
>>>>>>>>>> the CPU (although zipping is done in a specific background thread).
>>>>> To
>>>>>>>>>> reduce this effect, we are combining a time based rolling policy
>>>>> with a
>>>>>>>>>> sized based policy to zip smaller files, but this is not enough to
>>>>> make
>>>>>>>> the
>>>>>>>>>> system fully responsive at midnight.
>>>>>>>>>>
>>>>>>>>>> A pretty cool feature for us to avoid this issue is to have the
>>>>>>>> possibility
>>>>>>>>>> when a rolling is triggered because of a time based policy to change
>>>>>>>> file
>>>>>>>>>> immediately, but to wait for a random amount of time (within a
>>>>>>>> configurable
>>>>>>>>>> limit) before starting the compression. This random delay should
>>>>> help a
>>>>>>>> lot
>>>>>>>>>> to avoid contention on CPU cycles.
>>>>>>>>>>
>>>>>>>>>> Does log4j2 have something to solve this kind of issue ? If not,
>>>>> would
>>>>>>>> you
>>>>>>>>>> accept a pull request for this (I will open a Jira if needed) ?
>>>>>>>>>>
>>>>>>>>>> Regards,
>>>>>>>>>> Anthony
>>>>>>>>>>
>>>>>>>>
>>>>>>>> ---------------------------------------------------------------------
>>>>>>>> To unsubscribe, e-mail: [hidden email]
>>>>>>>> For additional commands, e-mail: [hidden email]
>>>>>>>>
>>>>>>>>
>>>>>> ---------------------------------------------------------------------
>>>>>> To unsubscribe, e-mail: [hidden email]
>>>>>> For additional commands, e-mail: [hidden email]
>>>>> ---------------------------------------------------------------------
>>>>> To unsubscribe, e-mail: [hidden email]
>>>>> For additional commands, e-mail: [hidden email]
>>>>>
>>>>>
>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: [hidden email]
>> For additional commands, e-mail: [hidden email]
>>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: [hidden email]
> For additional commands, e-mail: [hidden email]
>


---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Compression of rolled files : performance issue when lots of JVMs are using timed based policy

Remko Popma-2
Actually, there is already something like this because Log4j2 configuration has some support for scripting. I would prefer to enhance that over building conditional constructs in the configuration.

However, having to specify the exact rollover time for individual servers would result in a much more lengthy and involved configuration. Randomization is a commonly used technique to get roughly the same result without the inconvenience of precise configuration. I don't think it is such a bad idea.

Sent from my iPhone

> On Mar 24, 2017, at 19:35, Dominik Psenner <[hidden email]> wrote:
>
> What if a configuration could contain conditional statements? For instance:
>
> <Config>
>    <Define EnvironmentVariable="Hour" Value="12" />
>    <Define EnvironmentVariable="Minute" Value="0" />
>    <If EnvironmentVariable="JVM" Equals="JVM1">
>        <Define EnvironmentVariable="Minute" Value="0" />
>    </If>
>    <If EnvironmentVariable="JVM" Equals="JVM2">
>        <Define EnvironmentVariable="Minute" Value="1" />
>    </If>
>    <RollingFileAppender>
>        <RollingCondition>
>            <Cron Minute="$Minute" Hour="$Hour" DayOfMonth="*" Month="*" DayOfWeek="*" />
>        </RollingCondition>
>    </RollingFileAppender>
> </Config>
>
> Cheers
>
>> On 2017-03-24 11:08, Remko Popma wrote:
>> I see what you are saying, but the use case is to have a single configuration, that is what drives the request.
>>
>> Sent from my iPhone
>>
>>> On Mar 24, 2017, at 17:22, Dominik Psenner <[hidden email]> wrote:
>>>
>>> Hi there,
>>>
>>> Cron proved itself very to be stable and usable over the past years. FWIW, I would not recommend to introduce a randomization algorithm. An application that does things random means that the application does things when nobody expects it to do so. Further it does not solve the problem. One just needs enough JVMs to roll around at the same time with a randomizer does not produce large enough values to spread the rolling over a larger amount of time. The available CPU is then quickly drain out. In my opinion, it's better to configure the several rollings to be delayed, meaning that JVM1 rolls at 12:00, JVM2 rolls at 12:01, ...
>>>
>>> Cheers, Dominik
>>>
>>>> On 2017-03-23 15:04, Anthony Maire wrote:
>>>> https://issues.apache.org/jira/browse/LOG4J2-1855
>>>> https://github.com/apache/logging-log4j2/pull/68
>>>>
>>>> Let me know if you want me to do some changes
>>>>
>>>> Regards,
>>>> Anthony
>>>>
>>>>
>>>> 2017-03-23 13:15 GMT+01:00 Anthony Maire <[hidden email]>:
>>>>
>>>>> Ok,  I will open a jira ticket and provide a PR.
>>>>>
>>>>> Thanks for your input.
>>>>>
>>>>> Le 23 mars 2017 13:08, "Remko Popma" <[hidden email]> a écrit :
>>>>>
>>>>>> I see what you mean now. I agree it's better to keep the rollover concept
>>>>>> to mean file rename and compression that happen in sequence together. So
>>>>>> the randomization affects when the _sequence_ is triggered, not just one
>>>>>> part of the sequence. Makes sense.
>>>>>>
>>>>>> Sent from my iPhone
>>>>>>
>>>>>>> On Mar 23, 2017, at 16:28, Anthony Maire <[hidden email]>
>>>>>> wrote:
>>>>>>> Hi Remko
>>>>>>>
>>>>>>> My first idea was to have the rolling that triggers at the expected
>>>>>> time,
>>>>>>> and the compression that will be delayed. That's why I wanted the
>>>>>> delayed
>>>>>>> compression to occur before shutdown since the rolling already occurred.
>>>>>>>
>>>>>>> But I think that's a bad idea. First, it will lead to "fancy code" and I
>>>>>>> would like to avoid it too. But the main issue is that this behavior
>>>>>> should
>>>>>>> impact only the time based triggering when combining several policy. So
>>>>>> the
>>>>>>> code should be related to the triggering policy and not to the rolling
>>>>>>> strategy.
>>>>>>>
>>>>>>> So the best thing to do is to add some property on the timed base
>>>>>>> triggering policy and let that class handle all the logic and delay the
>>>>>>> triggering itself instead of the compression.
>>>>>>>
>>>>>>> Are you OK with that?
>>>>>>>
>>>>>>> Anthony
>>>>>>>
>>>>>>> Le 23 mars 2017 00:24, "Remko Popma" <[hidden email]> a écrit :
>>>>>>>
>>>>>>>
>>>>>>>> On Mar 23, 2017, at 1:06, Anthony Maire <[hidden email]>
>>>>>> wrote:
>>>>>>>> Thanks for these answers
>>>>>>>>
>>>>>>>> @Ralph : that was the kind of idea I had in mind : changing the
>>>>>>>> RollingFileManager.asyncExecutor to be a ScheduledThreadPoolExecutor,
>>>>>> and
>>>>>>>> based on some configuration, submitting task to be executed after a
>>>>>> random
>>>>>>>> delay. However with this kind of approach, special treatment should be
>>>>>>> made
>>>>>>>> if the manager is stopped with some pending delayed tasks in it.
>>>>>>> I'm okay with randomization except for this last bit about "special
>>>>>>> treatment...". Let's not make it too fancy. If the manager is stopped
>>>>>>> before it rolled over, then it didn't roll over, just like it works
>>>>>>> currently. I don't see the point of adding extra logic to trigger a
>>>>>>> rollover when the manager is stopped within the randomized time window.
>>>>>>>
>>>>>>>> @Matt : Cron policy can be a solution, but I don't know how to inject
>>>>>> some
>>>>>>>> random element in this to make the file roll at midnight + X random
>>>>>>>> seconds. Since there is a lot of JVM to manage and some of them can be
>>>>>>>> moved from a machine to another, I need to have a single log4j2.xml
>>>>>> file
>>>>>>>> for all environments. Moreover, our system administrators are
>>>>>> reluctant to
>>>>>>>> have something based on a shell-specific feature (such has the $RANDOM
>>>>>>>> variable from bash)
>>>>>>>>
>>>>>>>> Anthony
>>>>>>>>
>>>>>>>> 2017-03-22 16:31 GMT+01:00 Ralph Goers <[hidden email]>:
>>>>>>>>
>>>>>>>>> These are separate JVMs, so having a single executor would be of no
>>>>>> help.
>>>>>>>>> I believe the only way to do what you are asking for is to add
>>>>>>>>> configuration so that the asynchronous thread has a semi-random delay
>>>>>>> when
>>>>>>>>> it starts.
>>>>>>>>>
>>>>>>>>> Ralph
>>>>>>>>>
>>>>>>>>>> On Mar 22, 2017, at 7:58 AM, Greg Thomas <[hidden email]>
>>>>>>>>> wrote:
>>>>>>>>>>> One common issue we have with that framework (and I assume we can
>>>>>> have
>>>>>>>>> the
>>>>>>>>>>> same with log4j2) is that all of our JVMs (we can have more than 50
>>>>>>>>> JVMs on
>>>>>>>>>>> the same server in production) roll their file at midnight.
>>>>>>>>>>>
>>>>>>>>>>> When this happens, the system became often not usable for a few
>>>>>> seconds
>>>>>>>>>>> because of the simultaneous zipping of all the rolled files that
>>>>>>>>> overload
>>>>>>>>>>> the CPU (although zipping is done in a specific background thread).
>>>>>>>>>> ISTR that with the most recent versions of log4j, these threads are
>>>>>> in a
>>>>>>>>>> thread pool so that they are properly shutdown at the right time. I
>>>>>>>>> wonder
>>>>>>>>>> if it's possible (or could be possible) to somehow inject a thread
>>>>>> pool
>>>>>>>>> in
>>>>>>>>>> to log4j for this rollover, so that for you use case you could
>>>>>> inject a
>>>>>>>>>> single thread executor, so only one thread is ever compressing at a
>>>>>>> time.
>>>>>>>>>> Just a thought, anyway,
>>>>>>>>>>
>>>>>>>>>> Greg
>>>>>>>>>>
>>>>>>>>>> On 22 March 2017 at 13:47, Anthony Maire <[hidden email]>
>>>>>>>>> wrote:
>>>>>>>>>>> Hi
>>>>>>>>>>>
>>>>>>>>>>> We are currently using another logging framework in production, but
>>>>>> I'm
>>>>>>>>>>> pushing to change it for log4j2.
>>>>>>>>>>>
>>>>>>>>>>> One common issue we have with that framework (and I assume we can
>>>>>> have
>>>>>>>>> the
>>>>>>>>>>> same with log4j2) is that all of our JVMs (we can have more than 50
>>>>>>>>> JVMs on
>>>>>>>>>>> the same server in production) roll their file at midnight.
>>>>>>>>>>>
>>>>>>>>>>> When this happens, the system became often not usable for a few
>>>>>> seconds
>>>>>>>>>>> because of the simultaneous zipping of all the rolled files that
>>>>>>>>> overload
>>>>>>>>>>> the CPU (although zipping is done in a specific background thread).
>>>>>> To
>>>>>>>>>>> reduce this effect, we are combining a time based rolling policy
>>>>>> with a
>>>>>>>>>>> sized based policy to zip smaller files, but this is not enough to
>>>>>> make
>>>>>>>>> the
>>>>>>>>>>> system fully responsive at midnight.
>>>>>>>>>>>
>>>>>>>>>>> A pretty cool feature for us to avoid this issue is to have the
>>>>>>>>> possibility
>>>>>>>>>>> when a rolling is triggered because of a time based policy to change
>>>>>>>>> file
>>>>>>>>>>> immediately, but to wait for a random amount of time (within a
>>>>>>>>> configurable
>>>>>>>>>>> limit) before starting the compression. This random delay should
>>>>>> help a
>>>>>>>>> lot
>>>>>>>>>>> to avoid contention on CPU cycles.
>>>>>>>>>>>
>>>>>>>>>>> Does log4j2 have something to solve this kind of issue ? If not,
>>>>>> would
>>>>>>>>> you
>>>>>>>>>>> accept a pull request for this (I will open a Jira if needed) ?
>>>>>>>>>>>
>>>>>>>>>>> Regards,
>>>>>>>>>>> Anthony
>>>>>>>>>>>
>>>>>>>>>
>>>>>>>>> ---------------------------------------------------------------------
>>>>>>>>> To unsubscribe, e-mail: [hidden email]
>>>>>>>>> For additional commands, e-mail: [hidden email]
>>>>>>>>>
>>>>>>>>>
>>>>>>> ---------------------------------------------------------------------
>>>>>>> To unsubscribe, e-mail: [hidden email]
>>>>>>> For additional commands, e-mail: [hidden email]
>>>>>> ---------------------------------------------------------------------
>>>>>> To unsubscribe, e-mail: [hidden email]
>>>>>> For additional commands, e-mail: [hidden email]
>>>>>>
>>>>>>
>>>
>>> ---------------------------------------------------------------------
>>> To unsubscribe, e-mail: [hidden email]
>>> For additional commands, e-mail: [hidden email]
>>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: [hidden email]
>> For additional commands, e-mail: [hidden email]
>>
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: [hidden email]
> For additional commands, e-mail: [hidden email]
>

---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Compression of rolled files : performance issue when lots of JVMs are using timed based policy

Ralph Goers
In reply to this post by Dominik Psenner-2
The problem is that they want the files to roll over exactly at midnight so that they contain that day’s log files. They just don’t want the compression to happen all at the same time.  If that wasn’t the requirement the existing CronTriggeringPolicy would already solve the problem.

Ralph

> On Mar 24, 2017, at 3:35 AM, Dominik Psenner <[hidden email]> wrote:
>
> What if a configuration could contain conditional statements? For instance:
>
> <Config>
> <Define EnvironmentVariable="Hour" Value="12" />
> <Define EnvironmentVariable="Minute" Value="0" />
> <If EnvironmentVariable="JVM" Equals="JVM1">
> <Define EnvironmentVariable="Minute" Value="0" />
> </If>
> <If EnvironmentVariable="JVM" Equals="JVM2">
> <Define EnvironmentVariable="Minute" Value="1" />
> </If>
> <RollingFileAppender>
> <RollingCondition>
> <Cron Minute="$Minute" Hour="$Hour" DayOfMonth="*" Month="*" DayOfWeek="*" />
> </RollingCondition>
> </RollingFileAppender>
> </Config>
>
> Cheers
>
> On 2017-03-24 11:08, Remko Popma wrote:
>> I see what you are saying, but the use case is to have a single configuration, that is what drives the request.
>>
>> Sent from my iPhone
>>
>>> On Mar 24, 2017, at 17:22, Dominik Psenner <[hidden email]> wrote:
>>>
>>> Hi there,
>>>
>>> Cron proved itself very to be stable and usable over the past years. FWIW, I would not recommend to introduce a randomization algorithm. An application that does things random means that the application does things when nobody expects it to do so. Further it does not solve the problem. One just needs enough JVMs to roll around at the same time with a randomizer does not produce large enough values to spread the rolling over a larger amount of time. The available CPU is then quickly drain out. In my opinion, it's better to configure the several rollings to be delayed, meaning that JVM1 rolls at 12:00, JVM2 rolls at 12:01, ...
>>>
>>> Cheers, Dominik
>>>
>>>> On 2017-03-23 15:04, Anthony Maire wrote:
>>>> https://issues.apache.org/jira/browse/LOG4J2-1855
>>>> https://github.com/apache/logging-log4j2/pull/68
>>>>
>>>> Let me know if you want me to do some changes
>>>>
>>>> Regards,
>>>> Anthony
>>>>
>>>>
>>>> 2017-03-23 13:15 GMT+01:00 Anthony Maire <[hidden email]>:
>>>>
>>>>> Ok,  I will open a jira ticket and provide a PR.
>>>>>
>>>>> Thanks for your input.
>>>>>
>>>>> Le 23 mars 2017 13:08, "Remko Popma" <[hidden email]> a écrit :
>>>>>
>>>>>> I see what you mean now. I agree it's better to keep the rollover concept
>>>>>> to mean file rename and compression that happen in sequence together. So
>>>>>> the randomization affects when the _sequence_ is triggered, not just one
>>>>>> part of the sequence. Makes sense.
>>>>>>
>>>>>> Sent from my iPhone
>>>>>>
>>>>>>> On Mar 23, 2017, at 16:28, Anthony Maire <[hidden email]>
>>>>>> wrote:
>>>>>>> Hi Remko
>>>>>>>
>>>>>>> My first idea was to have the rolling that triggers at the expected
>>>>>> time,
>>>>>>> and the compression that will be delayed. That's why I wanted the
>>>>>> delayed
>>>>>>> compression to occur before shutdown since the rolling already occurred.
>>>>>>>
>>>>>>> But I think that's a bad idea. First, it will lead to "fancy code" and I
>>>>>>> would like to avoid it too. But the main issue is that this behavior
>>>>>> should
>>>>>>> impact only the time based triggering when combining several policy. So
>>>>>> the
>>>>>>> code should be related to the triggering policy and not to the rolling
>>>>>>> strategy.
>>>>>>>
>>>>>>> So the best thing to do is to add some property on the timed base
>>>>>>> triggering policy and let that class handle all the logic and delay the
>>>>>>> triggering itself instead of the compression.
>>>>>>>
>>>>>>> Are you OK with that?
>>>>>>>
>>>>>>> Anthony
>>>>>>>
>>>>>>> Le 23 mars 2017 00:24, "Remko Popma" <[hidden email]> a écrit :
>>>>>>>
>>>>>>>
>>>>>>>> On Mar 23, 2017, at 1:06, Anthony Maire <[hidden email]>
>>>>>> wrote:
>>>>>>>> Thanks for these answers
>>>>>>>>
>>>>>>>> @Ralph : that was the kind of idea I had in mind : changing the
>>>>>>>> RollingFileManager.asyncExecutor to be a ScheduledThreadPoolExecutor,
>>>>>> and
>>>>>>>> based on some configuration, submitting task to be executed after a
>>>>>> random
>>>>>>>> delay. However with this kind of approach, special treatment should be
>>>>>>> made
>>>>>>>> if the manager is stopped with some pending delayed tasks in it.
>>>>>>> I'm okay with randomization except for this last bit about "special
>>>>>>> treatment...". Let's not make it too fancy. If the manager is stopped
>>>>>>> before it rolled over, then it didn't roll over, just like it works
>>>>>>> currently. I don't see the point of adding extra logic to trigger a
>>>>>>> rollover when the manager is stopped within the randomized time window.
>>>>>>>
>>>>>>>> @Matt : Cron policy can be a solution, but I don't know how to inject
>>>>>> some
>>>>>>>> random element in this to make the file roll at midnight + X random
>>>>>>>> seconds. Since there is a lot of JVM to manage and some of them can be
>>>>>>>> moved from a machine to another, I need to have a single log4j2.xml
>>>>>> file
>>>>>>>> for all environments. Moreover, our system administrators are
>>>>>> reluctant to
>>>>>>>> have something based on a shell-specific feature (such has the $RANDOM
>>>>>>>> variable from bash)
>>>>>>>>
>>>>>>>> Anthony
>>>>>>>>
>>>>>>>> 2017-03-22 16:31 GMT+01:00 Ralph Goers <[hidden email]>:
>>>>>>>>
>>>>>>>>> These are separate JVMs, so having a single executor would be of no
>>>>>> help.
>>>>>>>>> I believe the only way to do what you are asking for is to add
>>>>>>>>> configuration so that the asynchronous thread has a semi-random delay
>>>>>>> when
>>>>>>>>> it starts.
>>>>>>>>>
>>>>>>>>> Ralph
>>>>>>>>>
>>>>>>>>>> On Mar 22, 2017, at 7:58 AM, Greg Thomas <[hidden email]>
>>>>>>>>> wrote:
>>>>>>>>>>> One common issue we have with that framework (and I assume we can
>>>>>> have
>>>>>>>>> the
>>>>>>>>>>> same with log4j2) is that all of our JVMs (we can have more than 50
>>>>>>>>> JVMs on
>>>>>>>>>>> the same server in production) roll their file at midnight.
>>>>>>>>>>>
>>>>>>>>>>> When this happens, the system became often not usable for a few
>>>>>> seconds
>>>>>>>>>>> because of the simultaneous zipping of all the rolled files that
>>>>>>>>> overload
>>>>>>>>>>> the CPU (although zipping is done in a specific background thread).
>>>>>>>>>> ISTR that with the most recent versions of log4j, these threads are
>>>>>> in a
>>>>>>>>>> thread pool so that they are properly shutdown at the right time. I
>>>>>>>>> wonder
>>>>>>>>>> if it's possible (or could be possible) to somehow inject a thread
>>>>>> pool
>>>>>>>>> in
>>>>>>>>>> to log4j for this rollover, so that for you use case you could
>>>>>> inject a
>>>>>>>>>> single thread executor, so only one thread is ever compressing at a
>>>>>>> time.
>>>>>>>>>> Just a thought, anyway,
>>>>>>>>>>
>>>>>>>>>> Greg
>>>>>>>>>>
>>>>>>>>>> On 22 March 2017 at 13:47, Anthony Maire <[hidden email]>
>>>>>>>>> wrote:
>>>>>>>>>>> Hi
>>>>>>>>>>>
>>>>>>>>>>> We are currently using another logging framework in production, but
>>>>>> I'm
>>>>>>>>>>> pushing to change it for log4j2.
>>>>>>>>>>>
>>>>>>>>>>> One common issue we have with that framework (and I assume we can
>>>>>> have
>>>>>>>>> the
>>>>>>>>>>> same with log4j2) is that all of our JVMs (we can have more than 50
>>>>>>>>> JVMs on
>>>>>>>>>>> the same server in production) roll their file at midnight.
>>>>>>>>>>>
>>>>>>>>>>> When this happens, the system became often not usable for a few
>>>>>> seconds
>>>>>>>>>>> because of the simultaneous zipping of all the rolled files that
>>>>>>>>> overload
>>>>>>>>>>> the CPU (although zipping is done in a specific background thread).
>>>>>> To
>>>>>>>>>>> reduce this effect, we are combining a time based rolling policy
>>>>>> with a
>>>>>>>>>>> sized based policy to zip smaller files, but this is not enough to
>>>>>> make
>>>>>>>>> the
>>>>>>>>>>> system fully responsive at midnight.
>>>>>>>>>>>
>>>>>>>>>>> A pretty cool feature for us to avoid this issue is to have the
>>>>>>>>> possibility
>>>>>>>>>>> when a rolling is triggered because of a time based policy to change
>>>>>>>>> file
>>>>>>>>>>> immediately, but to wait for a random amount of time (within a
>>>>>>>>> configurable
>>>>>>>>>>> limit) before starting the compression. This random delay should
>>>>>> help a
>>>>>>>>> lot
>>>>>>>>>>> to avoid contention on CPU cycles.
>>>>>>>>>>>
>>>>>>>>>>> Does log4j2 have something to solve this kind of issue ? If not,
>>>>>> would
>>>>>>>>> you
>>>>>>>>>>> accept a pull request for this (I will open a Jira if needed) ?
>>>>>>>>>>>
>>>>>>>>>>> Regards,
>>>>>>>>>>> Anthony
>>>>>>>>>>>
>>>>>>>>>
>>>>>>>>> ---------------------------------------------------------------------
>>>>>>>>> To unsubscribe, e-mail: [hidden email]
>>>>>>>>> For additional commands, e-mail: [hidden email]
>>>>>>>>>
>>>>>>>>>
>>>>>>> ---------------------------------------------------------------------
>>>>>>> To unsubscribe, e-mail: [hidden email]
>>>>>>> For additional commands, e-mail: [hidden email]
>>>>>> ---------------------------------------------------------------------
>>>>>> To unsubscribe, e-mail: [hidden email]
>>>>>> For additional commands, e-mail: [hidden email]
>>>>>>
>>>>>>
>>>
>>> ---------------------------------------------------------------------
>>> To unsubscribe, e-mail: [hidden email]
>>> For additional commands, e-mail: [hidden email]
>>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: [hidden email]
>> For additional commands, e-mail: [hidden email]
>>
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: [hidden email]
> For additional commands, e-mail: [hidden email]
>
>



---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Compression of rolled files : performance issue when lots of JVMs are using timed based policy

Anthony Maire
In reply to this post by Remko Popma-2
Basically we are hosting distributed systems for our clients. So we have
several dozens of JVM per physical host, and several dozens of physical
hosts. Moreover some clients are sometimes moved from one machine to
another so having a single configuration file is a very huge requirement.

Having the file that rolls precisely at midnight is a nice to have. Having
the rolling that happen a little later because of randomization can be
accepted if it solve the performance issue (which stay pretty short, it's
about 15 seconds during which we can experience a few hundreds of
milliseconds long stalls but this is already too much in our industry )

Randomization is a common technique for that kind of issue, used in
congestion avoidance in some network protocols for example (including
Ethernet ). Having 2 or 3 jvm that roll at the same time is not a big deal,
we have enough free cpu cycles for that. That's why randomization during a
few minutes seems OK to me : we don't need to annihilate collisions,
greatly reduce them is OK

Basically I'm open to any solution as long as it can be deployed everywhere
without any OS/shell dependant trick and it does not involve any kind of
per JVM configuration. The patch I submitted is an option, but I'd be glad
to use another option that match these requirements.

Regards,
Anthony


Le 24 mars 2017 15:20, "Remko Popma" <[hidden email]> a écrit :

Actually, there is already something like this because Log4j2 configuration
has some support for scripting. I would prefer to enhance that over
building conditional constructs in the configuration.

However, having to specify the exact rollover time for individual servers
would result in a much more lengthy and involved configuration.
Randomization is a commonly used technique to get roughly the same result
without the inconvenience of precise configuration. I don't think it is
such a bad idea.

Sent from my iPhone

> On Mar 24, 2017, at 19:35, Dominik Psenner <[hidden email]> wrote:
>
> What if a configuration could contain conditional statements? For
instance:

>
> <Config>
>    <Define EnvironmentVariable="Hour" Value="12" />
>    <Define EnvironmentVariable="Minute" Value="0" />
>    <If EnvironmentVariable="JVM" Equals="JVM1">
>        <Define EnvironmentVariable="Minute" Value="0" />
>    </If>
>    <If EnvironmentVariable="JVM" Equals="JVM2">
>        <Define EnvironmentVariable="Minute" Value="1" />
>    </If>
>    <RollingFileAppender>
>        <RollingCondition>
>            <Cron Minute="$Minute" Hour="$Hour" DayOfMonth="*" Month="*"
DayOfWeek="*" />
>        </RollingCondition>
>    </RollingFileAppender>
> </Config>
>
> Cheers
>
>> On 2017-03-24 11:08, Remko Popma wrote:
>> I see what you are saying, but the use case is to have a single
configuration, that is what drives the request.
>>
>> Sent from my iPhone
>>
>>> On Mar 24, 2017, at 17:22, Dominik Psenner <[hidden email]> wrote:
>>>
>>> Hi there,
>>>
>>> Cron proved itself very to be stable and usable over the past years.
FWIW, I would not recommend to introduce a randomization algorithm. An
application that does things random means that the application does things
when nobody expects it to do so. Further it does not solve the problem. One
just needs enough JVMs to roll around at the same time with a randomizer
does not produce large enough values to spread the rolling over a larger
amount of time. The available CPU is then quickly drain out. In my opinion,
it's better to configure the several rollings to be delayed, meaning that
JVM1 rolls at 12:00, JVM2 rolls at 12:01, ...

>>>
>>> Cheers, Dominik
>>>
>>>> On 2017-03-23 15:04, Anthony Maire wrote:
>>>> https://issues.apache.org/jira/browse/LOG4J2-1855
>>>> https://github.com/apache/logging-log4j2/pull/68
>>>>
>>>> Let me know if you want me to do some changes
>>>>
>>>> Regards,
>>>> Anthony
>>>>
>>>>
>>>> 2017-03-23 13:15 GMT+01:00 Anthony Maire <[hidden email]>:
>>>>
>>>>> Ok,  I will open a jira ticket and provide a PR.
>>>>>
>>>>> Thanks for your input.
>>>>>
>>>>> Le 23 mars 2017 13:08, "Remko Popma" <[hidden email]> a écrit :
>>>>>
>>>>>> I see what you mean now. I agree it's better to keep the rollover
concept
>>>>>> to mean file rename and compression that happen in sequence
together. So
>>>>>> the randomization affects when the _sequence_ is triggered, not just
one

>>>>>> part of the sequence. Makes sense.
>>>>>>
>>>>>> Sent from my iPhone
>>>>>>
>>>>>>> On Mar 23, 2017, at 16:28, Anthony Maire <[hidden email]>
>>>>>> wrote:
>>>>>>> Hi Remko
>>>>>>>
>>>>>>> My first idea was to have the rolling that triggers at the expected
>>>>>> time,
>>>>>>> and the compression that will be delayed. That's why I wanted the
>>>>>> delayed
>>>>>>> compression to occur before shutdown since the rolling already
occurred.
>>>>>>>
>>>>>>> But I think that's a bad idea. First, it will lead to "fancy code"
and I
>>>>>>> would like to avoid it too. But the main issue is that this behavior
>>>>>> should
>>>>>>> impact only the time based triggering when combining several
policy. So
>>>>>> the
>>>>>>> code should be related to the triggering policy and not to the
rolling
>>>>>>> strategy.
>>>>>>>
>>>>>>> So the best thing to do is to add some property on the timed base
>>>>>>> triggering policy and let that class handle all the logic and delay
the
>>>>>>> triggering itself instead of the compression.
>>>>>>>
>>>>>>> Are you OK with that?
>>>>>>>
>>>>>>> Anthony
>>>>>>>
>>>>>>> Le 23 mars 2017 00:24, "Remko Popma" <[hidden email]> a
écrit :
>>>>>>>
>>>>>>>
>>>>>>>> On Mar 23, 2017, at 1:06, Anthony Maire <[hidden email]>
>>>>>> wrote:
>>>>>>>> Thanks for these answers
>>>>>>>>
>>>>>>>> @Ralph : that was the kind of idea I had in mind : changing the
>>>>>>>> RollingFileManager.asyncExecutor to be a
ScheduledThreadPoolExecutor,
>>>>>> and
>>>>>>>> based on some configuration, submitting task to be executed after a
>>>>>> random
>>>>>>>> delay. However with this kind of approach, special treatment
should be
>>>>>>> made
>>>>>>>> if the manager is stopped with some pending delayed tasks in it.
>>>>>>> I'm okay with randomization except for this last bit about "special
>>>>>>> treatment...". Let's not make it too fancy. If the manager is
stopped
>>>>>>> before it rolled over, then it didn't roll over, just like it works
>>>>>>> currently. I don't see the point of adding extra logic to trigger a
>>>>>>> rollover when the manager is stopped within the randomized time
window.
>>>>>>>
>>>>>>>> @Matt : Cron policy can be a solution, but I don't know how to
inject
>>>>>> some
>>>>>>>> random element in this to make the file roll at midnight + X random
>>>>>>>> seconds. Since there is a lot of JVM to manage and some of them
can be
>>>>>>>> moved from a machine to another, I need to have a single log4j2.xml
>>>>>> file
>>>>>>>> for all environments. Moreover, our system administrators are
>>>>>> reluctant to
>>>>>>>> have something based on a shell-specific feature (such has the
$RANDOM
>>>>>>>> variable from bash)
>>>>>>>>
>>>>>>>> Anthony
>>>>>>>>
>>>>>>>> 2017-03-22 16:31 GMT+01:00 Ralph Goers <[hidden email]
>:
>>>>>>>>
>>>>>>>>> These are separate JVMs, so having a single executor would be of
no
>>>>>> help.
>>>>>>>>> I believe the only way to do what you are asking for is to add
>>>>>>>>> configuration so that the asynchronous thread has a semi-random
delay
>>>>>>> when
>>>>>>>>> it starts.
>>>>>>>>>
>>>>>>>>> Ralph
>>>>>>>>>
>>>>>>>>>> On Mar 22, 2017, at 7:58 AM, Greg Thomas <[hidden email]
>
>>>>>>>>> wrote:
>>>>>>>>>>> One common issue we have with that framework (and I assume we
can
>>>>>> have
>>>>>>>>> the
>>>>>>>>>>> same with log4j2) is that all of our JVMs (we can have more
than 50
>>>>>>>>> JVMs on
>>>>>>>>>>> the same server in production) roll their file at midnight.
>>>>>>>>>>>
>>>>>>>>>>> When this happens, the system became often not usable for a few
>>>>>> seconds
>>>>>>>>>>> because of the simultaneous zipping of all the rolled files that
>>>>>>>>> overload
>>>>>>>>>>> the CPU (although zipping is done in a specific background
thread).
>>>>>>>>>> ISTR that with the most recent versions of log4j, these threads
are
>>>>>> in a
>>>>>>>>>> thread pool so that they are properly shutdown at the right
time. I
>>>>>>>>> wonder
>>>>>>>>>> if it's possible (or could be possible) to somehow inject a
thread
>>>>>> pool
>>>>>>>>> in
>>>>>>>>>> to log4j for this rollover, so that for you use case you could
>>>>>> inject a
>>>>>>>>>> single thread executor, so only one thread is ever compressing
at a

>>>>>>> time.
>>>>>>>>>> Just a thought, anyway,
>>>>>>>>>>
>>>>>>>>>> Greg
>>>>>>>>>>
>>>>>>>>>> On 22 March 2017 at 13:47, Anthony Maire <[hidden email]
>
>>>>>>>>> wrote:
>>>>>>>>>>> Hi
>>>>>>>>>>>
>>>>>>>>>>> We are currently using another logging framework in production,
but
>>>>>> I'm
>>>>>>>>>>> pushing to change it for log4j2.
>>>>>>>>>>>
>>>>>>>>>>> One common issue we have with that framework (and I assume we
can
>>>>>> have
>>>>>>>>> the
>>>>>>>>>>> same with log4j2) is that all of our JVMs (we can have more
than 50
>>>>>>>>> JVMs on
>>>>>>>>>>> the same server in production) roll their file at midnight.
>>>>>>>>>>>
>>>>>>>>>>> When this happens, the system became often not usable for a few
>>>>>> seconds
>>>>>>>>>>> because of the simultaneous zipping of all the rolled files that
>>>>>>>>> overload
>>>>>>>>>>> the CPU (although zipping is done in a specific background
thread).
>>>>>> To
>>>>>>>>>>> reduce this effect, we are combining a time based rolling policy
>>>>>> with a
>>>>>>>>>>> sized based policy to zip smaller files, but this is not enough
to
>>>>>> make
>>>>>>>>> the
>>>>>>>>>>> system fully responsive at midnight.
>>>>>>>>>>>
>>>>>>>>>>> A pretty cool feature for us to avoid this issue is to have the
>>>>>>>>> possibility
>>>>>>>>>>> when a rolling is triggered because of a time based policy to
change

>>>>>>>>> file
>>>>>>>>>>> immediately, but to wait for a random amount of time (within a
>>>>>>>>> configurable
>>>>>>>>>>> limit) before starting the compression. This random delay should
>>>>>> help a
>>>>>>>>> lot
>>>>>>>>>>> to avoid contention on CPU cycles.
>>>>>>>>>>>
>>>>>>>>>>> Does log4j2 have something to solve this kind of issue ? If not,
>>>>>> would
>>>>>>>>> you
>>>>>>>>>>> accept a pull request for this (I will open a Jira if needed) ?
>>>>>>>>>>>
>>>>>>>>>>> Regards,
>>>>>>>>>>> Anthony
>>>>>>>>>>>
>>>>>>>>>
>>>>>>>>> ------------------------------------------------------------
---------
>>>>>>>>> To unsubscribe, e-mail: [hidden email]
>>>>>>>>> For additional commands, e-mail: log4j-user-help@logging.
apache.org
>>>>>>>>>
>>>>>>>>>
>>>>>>> ------------------------------------------------------------
---------

>>>>>>> To unsubscribe, e-mail: [hidden email]
>>>>>>> For additional commands, e-mail: [hidden email]
>>>>>> ---------------------------------------------------------------------
>>>>>> To unsubscribe, e-mail: [hidden email]
>>>>>> For additional commands, e-mail: [hidden email]
>>>>>>
>>>>>>
>>>
>>> ---------------------------------------------------------------------
>>> To unsubscribe, e-mail: [hidden email]
>>> For additional commands, e-mail: [hidden email]
>>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: [hidden email]
>> For additional commands, e-mail: [hidden email]
>>
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: [hidden email]
> For additional commands, e-mail: [hidden email]
>

---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Compression of rolled files : performance issue when lots of JVMs are using timed based policy

Ralph Goers
I thought CronTriggeringPolicy would handle this but it is based on Quartz’ CronExpression which doesn’t support randomizing fields. I was confused because Jenkins supports this and I had thought it was using Quartz. Apparently not.

Ralph


> On Mar 24, 2017, at 10:15 AM, Anthony Maire <[hidden email]> wrote:
>
> Basically we are hosting distributed systems for our clients. So we have
> several dozens of JVM per physical host, and several dozens of physical
> hosts. Moreover some clients are sometimes moved from one machine to
> another so having a single configuration file is a very huge requirement.
>
> Having the file that rolls precisely at midnight is a nice to have. Having
> the rolling that happen a little later because of randomization can be
> accepted if it solve the performance issue (which stay pretty short, it's
> about 15 seconds during which we can experience a few hundreds of
> milliseconds long stalls but this is already too much in our industry )
>
> Randomization is a common technique for that kind of issue, used in
> congestion avoidance in some network protocols for example (including
> Ethernet ). Having 2 or 3 jvm that roll at the same time is not a big deal,
> we have enough free cpu cycles for that. That's why randomization during a
> few minutes seems OK to me : we don't need to annihilate collisions,
> greatly reduce them is OK
>
> Basically I'm open to any solution as long as it can be deployed everywhere
> without any OS/shell dependant trick and it does not involve any kind of
> per JVM configuration. The patch I submitted is an option, but I'd be glad
> to use another option that match these requirements.
>
> Regards,
> Anthony
>
>
> Le 24 mars 2017 15:20, "Remko Popma" <[hidden email]> a écrit :
>
> Actually, there is already something like this because Log4j2 configuration
> has some support for scripting. I would prefer to enhance that over
> building conditional constructs in the configuration.
>
> However, having to specify the exact rollover time for individual servers
> would result in a much more lengthy and involved configuration.
> Randomization is a commonly used technique to get roughly the same result
> without the inconvenience of precise configuration. I don't think it is
> such a bad idea.
>
> Sent from my iPhone
>
>> On Mar 24, 2017, at 19:35, Dominik Psenner <[hidden email]> wrote:
>>
>> What if a configuration could contain conditional statements? For
> instance:
>>
>> <Config>
>>   <Define EnvironmentVariable="Hour" Value="12" />
>>   <Define EnvironmentVariable="Minute" Value="0" />
>>   <If EnvironmentVariable="JVM" Equals="JVM1">
>>       <Define EnvironmentVariable="Minute" Value="0" />
>>   </If>
>>   <If EnvironmentVariable="JVM" Equals="JVM2">
>>       <Define EnvironmentVariable="Minute" Value="1" />
>>   </If>
>>   <RollingFileAppender>
>>       <RollingCondition>
>>           <Cron Minute="$Minute" Hour="$Hour" DayOfMonth="*" Month="*"
> DayOfWeek="*" />
>>       </RollingCondition>
>>   </RollingFileAppender>
>> </Config>
>>
>> Cheers
>>
>>> On 2017-03-24 11:08, Remko Popma wrote:
>>> I see what you are saying, but the use case is to have a single
> configuration, that is what drives the request.
>>>
>>> Sent from my iPhone
>>>
>>>> On Mar 24, 2017, at 17:22, Dominik Psenner <[hidden email]> wrote:
>>>>
>>>> Hi there,
>>>>
>>>> Cron proved itself very to be stable and usable over the past years.
> FWIW, I would not recommend to introduce a randomization algorithm. An
> application that does things random means that the application does things
> when nobody expects it to do so. Further it does not solve the problem. One
> just needs enough JVMs to roll around at the same time with a randomizer
> does not produce large enough values to spread the rolling over a larger
> amount of time. The available CPU is then quickly drain out. In my opinion,
> it's better to configure the several rollings to be delayed, meaning that
> JVM1 rolls at 12:00, JVM2 rolls at 12:01, ...
>>>>
>>>> Cheers, Dominik
>>>>
>>>>> On 2017-03-23 15:04, Anthony Maire wrote:
>>>>> https://issues.apache.org/jira/browse/LOG4J2-1855
>>>>> https://github.com/apache/logging-log4j2/pull/68
>>>>>
>>>>> Let me know if you want me to do some changes
>>>>>
>>>>> Regards,
>>>>> Anthony
>>>>>
>>>>>
>>>>> 2017-03-23 13:15 GMT+01:00 Anthony Maire <[hidden email]>:
>>>>>
>>>>>> Ok,  I will open a jira ticket and provide a PR.
>>>>>>
>>>>>> Thanks for your input.
>>>>>>
>>>>>> Le 23 mars 2017 13:08, "Remko Popma" <[hidden email]> a écrit :
>>>>>>
>>>>>>> I see what you mean now. I agree it's better to keep the rollover
> concept
>>>>>>> to mean file rename and compression that happen in sequence
> together. So
>>>>>>> the randomization affects when the _sequence_ is triggered, not just
> one
>>>>>>> part of the sequence. Makes sense.
>>>>>>>
>>>>>>> Sent from my iPhone
>>>>>>>
>>>>>>>> On Mar 23, 2017, at 16:28, Anthony Maire <[hidden email]>
>>>>>>> wrote:
>>>>>>>> Hi Remko
>>>>>>>>
>>>>>>>> My first idea was to have the rolling that triggers at the expected
>>>>>>> time,
>>>>>>>> and the compression that will be delayed. That's why I wanted the
>>>>>>> delayed
>>>>>>>> compression to occur before shutdown since the rolling already
> occurred.
>>>>>>>>
>>>>>>>> But I think that's a bad idea. First, it will lead to "fancy code"
> and I
>>>>>>>> would like to avoid it too. But the main issue is that this behavior
>>>>>>> should
>>>>>>>> impact only the time based triggering when combining several
> policy. So
>>>>>>> the
>>>>>>>> code should be related to the triggering policy and not to the
> rolling
>>>>>>>> strategy.
>>>>>>>>
>>>>>>>> So the best thing to do is to add some property on the timed base
>>>>>>>> triggering policy and let that class handle all the logic and delay
> the
>>>>>>>> triggering itself instead of the compression.
>>>>>>>>
>>>>>>>> Are you OK with that?
>>>>>>>>
>>>>>>>> Anthony
>>>>>>>>
>>>>>>>> Le 23 mars 2017 00:24, "Remko Popma" <[hidden email]> a
> écrit :
>>>>>>>>
>>>>>>>>
>>>>>>>>> On Mar 23, 2017, at 1:06, Anthony Maire <[hidden email]>
>>>>>>> wrote:
>>>>>>>>> Thanks for these answers
>>>>>>>>>
>>>>>>>>> @Ralph : that was the kind of idea I had in mind : changing the
>>>>>>>>> RollingFileManager.asyncExecutor to be a
> ScheduledThreadPoolExecutor,
>>>>>>> and
>>>>>>>>> based on some configuration, submitting task to be executed after a
>>>>>>> random
>>>>>>>>> delay. However with this kind of approach, special treatment
> should be
>>>>>>>> made
>>>>>>>>> if the manager is stopped with some pending delayed tasks in it.
>>>>>>>> I'm okay with randomization except for this last bit about "special
>>>>>>>> treatment...". Let's not make it too fancy. If the manager is
> stopped
>>>>>>>> before it rolled over, then it didn't roll over, just like it works
>>>>>>>> currently. I don't see the point of adding extra logic to trigger a
>>>>>>>> rollover when the manager is stopped within the randomized time
> window.
>>>>>>>>
>>>>>>>>> @Matt : Cron policy can be a solution, but I don't know how to
> inject
>>>>>>> some
>>>>>>>>> random element in this to make the file roll at midnight + X random
>>>>>>>>> seconds. Since there is a lot of JVM to manage and some of them
> can be
>>>>>>>>> moved from a machine to another, I need to have a single log4j2.xml
>>>>>>> file
>>>>>>>>> for all environments. Moreover, our system administrators are
>>>>>>> reluctant to
>>>>>>>>> have something based on a shell-specific feature (such has the
> $RANDOM
>>>>>>>>> variable from bash)
>>>>>>>>>
>>>>>>>>> Anthony
>>>>>>>>>
>>>>>>>>> 2017-03-22 16:31 GMT+01:00 Ralph Goers <[hidden email]
>> :
>>>>>>>>>
>>>>>>>>>> These are separate JVMs, so having a single executor would be of
> no
>>>>>>> help.
>>>>>>>>>> I believe the only way to do what you are asking for is to add
>>>>>>>>>> configuration so that the asynchronous thread has a semi-random
> delay
>>>>>>>> when
>>>>>>>>>> it starts.
>>>>>>>>>>
>>>>>>>>>> Ralph
>>>>>>>>>>
>>>>>>>>>>> On Mar 22, 2017, at 7:58 AM, Greg Thomas <[hidden email]
>>
>>>>>>>>>> wrote:
>>>>>>>>>>>> One common issue we have with that framework (and I assume we
> can
>>>>>>> have
>>>>>>>>>> the
>>>>>>>>>>>> same with log4j2) is that all of our JVMs (we can have more
> than 50
>>>>>>>>>> JVMs on
>>>>>>>>>>>> the same server in production) roll their file at midnight.
>>>>>>>>>>>>
>>>>>>>>>>>> When this happens, the system became often not usable for a few
>>>>>>> seconds
>>>>>>>>>>>> because of the simultaneous zipping of all the rolled files that
>>>>>>>>>> overload
>>>>>>>>>>>> the CPU (although zipping is done in a specific background
> thread).
>>>>>>>>>>> ISTR that with the most recent versions of log4j, these threads
> are
>>>>>>> in a
>>>>>>>>>>> thread pool so that they are properly shutdown at the right
> time. I
>>>>>>>>>> wonder
>>>>>>>>>>> if it's possible (or could be possible) to somehow inject a
> thread
>>>>>>> pool
>>>>>>>>>> in
>>>>>>>>>>> to log4j for this rollover, so that for you use case you could
>>>>>>> inject a
>>>>>>>>>>> single thread executor, so only one thread is ever compressing
> at a
>>>>>>>> time.
>>>>>>>>>>> Just a thought, anyway,
>>>>>>>>>>>
>>>>>>>>>>> Greg
>>>>>>>>>>>
>>>>>>>>>>> On 22 March 2017 at 13:47, Anthony Maire <[hidden email]
>>
>>>>>>>>>> wrote:
>>>>>>>>>>>> Hi
>>>>>>>>>>>>
>>>>>>>>>>>> We are currently using another logging framework in production,
> but
>>>>>>> I'm
>>>>>>>>>>>> pushing to change it for log4j2.
>>>>>>>>>>>>
>>>>>>>>>>>> One common issue we have with that framework (and I assume we
> can
>>>>>>> have
>>>>>>>>>> the
>>>>>>>>>>>> same with log4j2) is that all of our JVMs (we can have more
> than 50
>>>>>>>>>> JVMs on
>>>>>>>>>>>> the same server in production) roll their file at midnight.
>>>>>>>>>>>>
>>>>>>>>>>>> When this happens, the system became often not usable for a few
>>>>>>> seconds
>>>>>>>>>>>> because of the simultaneous zipping of all the rolled files that
>>>>>>>>>> overload
>>>>>>>>>>>> the CPU (although zipping is done in a specific background
> thread).
>>>>>>> To
>>>>>>>>>>>> reduce this effect, we are combining a time based rolling policy
>>>>>>> with a
>>>>>>>>>>>> sized based policy to zip smaller files, but this is not enough
> to
>>>>>>> make
>>>>>>>>>> the
>>>>>>>>>>>> system fully responsive at midnight.
>>>>>>>>>>>>
>>>>>>>>>>>> A pretty cool feature for us to avoid this issue is to have the
>>>>>>>>>> possibility
>>>>>>>>>>>> when a rolling is triggered because of a time based policy to
> change
>>>>>>>>>> file
>>>>>>>>>>>> immediately, but to wait for a random amount of time (within a
>>>>>>>>>> configurable
>>>>>>>>>>>> limit) before starting the compression. This random delay should
>>>>>>> help a
>>>>>>>>>> lot
>>>>>>>>>>>> to avoid contention on CPU cycles.
>>>>>>>>>>>>
>>>>>>>>>>>> Does log4j2 have something to solve this kind of issue ? If not,
>>>>>>> would
>>>>>>>>>> you
>>>>>>>>>>>> accept a pull request for this (I will open a Jira if needed) ?
>>>>>>>>>>>>
>>>>>>>>>>>> Regards,
>>>>>>>>>>>> Anthony
>>>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>> ------------------------------------------------------------
> ---------
>>>>>>>>>> To unsubscribe, e-mail: [hidden email]
>>>>>>>>>> For additional commands, e-mail: log4j-user-help@logging.
> apache.org
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>> ------------------------------------------------------------
> ---------
>>>>>>>> To unsubscribe, e-mail: [hidden email]
>>>>>>>> For additional commands, e-mail: [hidden email]
>>>>>>> ---------------------------------------------------------------------
>>>>>>> To unsubscribe, e-mail: [hidden email]
>>>>>>> For additional commands, e-mail: [hidden email]
>>>>>>>
>>>>>>>
>>>>
>>>> ---------------------------------------------------------------------
>>>> To unsubscribe, e-mail: [hidden email]
>>>> For additional commands, e-mail: [hidden email]
>>>>
>>> ---------------------------------------------------------------------
>>> To unsubscribe, e-mail: [hidden email]
>>> For additional commands, e-mail: [hidden email]
>>>
>>
>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: [hidden email]
>> For additional commands, e-mail: [hidden email]
>>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: [hidden email]
> For additional commands, e-mail: [hidden email]



---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Compression of rolled files : performance issue when lots of JVMs are using timed based policy

Anthony Maire
That's probably why I wasn't able to figure out how you can do this with
CronTrigerringPolicy :)
Do you think that adding this random support in cron expression is a better
solution ?

Regards,
Anthony

2017-03-24 18:47 GMT+01:00 Ralph Goers <[hidden email]>:

> I thought CronTriggeringPolicy would handle this but it is based on
> Quartz’ CronExpression which doesn’t support randomizing fields. I was
> confused because Jenkins supports this and I had thought it was using
> Quartz. Apparently not.
>
> Ralph
>
>
> > On Mar 24, 2017, at 10:15 AM, Anthony Maire <[hidden email]>
> wrote:
> >
> > Basically we are hosting distributed systems for our clients. So we have
> > several dozens of JVM per physical host, and several dozens of physical
> > hosts. Moreover some clients are sometimes moved from one machine to
> > another so having a single configuration file is a very huge requirement.
> >
> > Having the file that rolls precisely at midnight is a nice to have.
> Having
> > the rolling that happen a little later because of randomization can be
> > accepted if it solve the performance issue (which stay pretty short, it's
> > about 15 seconds during which we can experience a few hundreds of
> > milliseconds long stalls but this is already too much in our industry )
> >
> > Randomization is a common technique for that kind of issue, used in
> > congestion avoidance in some network protocols for example (including
> > Ethernet ). Having 2 or 3 jvm that roll at the same time is not a big
> deal,
> > we have enough free cpu cycles for that. That's why randomization during
> a
> > few minutes seems OK to me : we don't need to annihilate collisions,
> > greatly reduce them is OK
> >
> > Basically I'm open to any solution as long as it can be deployed
> everywhere
> > without any OS/shell dependant trick and it does not involve any kind of
> > per JVM configuration. The patch I submitted is an option, but I'd be
> glad
> > to use another option that match these requirements.
> >
> > Regards,
> > Anthony
> >
> >
> > Le 24 mars 2017 15:20, "Remko Popma" <[hidden email]> a écrit :
> >
> > Actually, there is already something like this because Log4j2
> configuration
> > has some support for scripting. I would prefer to enhance that over
> > building conditional constructs in the configuration.
> >
> > However, having to specify the exact rollover time for individual servers
> > would result in a much more lengthy and involved configuration.
> > Randomization is a commonly used technique to get roughly the same result
> > without the inconvenience of precise configuration. I don't think it is
> > such a bad idea.
> >
> > Sent from my iPhone
> >
> >> On Mar 24, 2017, at 19:35, Dominik Psenner <[hidden email]> wrote:
> >>
> >> What if a configuration could contain conditional statements? For
> > instance:
> >>
> >> <Config>
> >>   <Define EnvironmentVariable="Hour" Value="12" />
> >>   <Define EnvironmentVariable="Minute" Value="0" />
> >>   <If EnvironmentVariable="JVM" Equals="JVM1">
> >>       <Define EnvironmentVariable="Minute" Value="0" />
> >>   </If>
> >>   <If EnvironmentVariable="JVM" Equals="JVM2">
> >>       <Define EnvironmentVariable="Minute" Value="1" />
> >>   </If>
> >>   <RollingFileAppender>
> >>       <RollingCondition>
> >>           <Cron Minute="$Minute" Hour="$Hour" DayOfMonth="*" Month="*"
> > DayOfWeek="*" />
> >>       </RollingCondition>
> >>   </RollingFileAppender>
> >> </Config>
> >>
> >> Cheers
> >>
> >>> On 2017-03-24 11:08, Remko Popma wrote:
> >>> I see what you are saying, but the use case is to have a single
> > configuration, that is what drives the request.
> >>>
> >>> Sent from my iPhone
> >>>
> >>>> On Mar 24, 2017, at 17:22, Dominik Psenner <[hidden email]>
> wrote:
> >>>>
> >>>> Hi there,
> >>>>
> >>>> Cron proved itself very to be stable and usable over the past years.
> > FWIW, I would not recommend to introduce a randomization algorithm. An
> > application that does things random means that the application does
> things
> > when nobody expects it to do so. Further it does not solve the problem.
> One
> > just needs enough JVMs to roll around at the same time with a randomizer
> > does not produce large enough values to spread the rolling over a larger
> > amount of time. The available CPU is then quickly drain out. In my
> opinion,
> > it's better to configure the several rollings to be delayed, meaning that
> > JVM1 rolls at 12:00, JVM2 rolls at 12:01, ...
> >>>>
> >>>> Cheers, Dominik
> >>>>
> >>>>> On 2017-03-23 15:04, Anthony Maire wrote:
> >>>>> https://issues.apache.org/jira/browse/LOG4J2-1855
> >>>>> https://github.com/apache/logging-log4j2/pull/68
> >>>>>
> >>>>> Let me know if you want me to do some changes
> >>>>>
> >>>>> Regards,
> >>>>> Anthony
> >>>>>
> >>>>>
> >>>>> 2017-03-23 13:15 GMT+01:00 Anthony Maire <[hidden email]>:
> >>>>>
> >>>>>> Ok,  I will open a jira ticket and provide a PR.
> >>>>>>
> >>>>>> Thanks for your input.
> >>>>>>
> >>>>>> Le 23 mars 2017 13:08, "Remko Popma" <[hidden email]> a
> écrit :
> >>>>>>
> >>>>>>> I see what you mean now. I agree it's better to keep the rollover
> > concept
> >>>>>>> to mean file rename and compression that happen in sequence
> > together. So
> >>>>>>> the randomization affects when the _sequence_ is triggered, not
> just
> > one
> >>>>>>> part of the sequence. Makes sense.
> >>>>>>>
> >>>>>>> Sent from my iPhone
> >>>>>>>
> >>>>>>>> On Mar 23, 2017, at 16:28, Anthony Maire <[hidden email]
> >
> >>>>>>> wrote:
> >>>>>>>> Hi Remko
> >>>>>>>>
> >>>>>>>> My first idea was to have the rolling that triggers at the
> expected
> >>>>>>> time,
> >>>>>>>> and the compression that will be delayed. That's why I wanted the
> >>>>>>> delayed
> >>>>>>>> compression to occur before shutdown since the rolling already
> > occurred.
> >>>>>>>>
> >>>>>>>> But I think that's a bad idea. First, it will lead to "fancy code"
> > and I
> >>>>>>>> would like to avoid it too. But the main issue is that this
> behavior
> >>>>>>> should
> >>>>>>>> impact only the time based triggering when combining several
> > policy. So
> >>>>>>> the
> >>>>>>>> code should be related to the triggering policy and not to the
> > rolling
> >>>>>>>> strategy.
> >>>>>>>>
> >>>>>>>> So the best thing to do is to add some property on the timed base
> >>>>>>>> triggering policy and let that class handle all the logic and
> delay
> > the
> >>>>>>>> triggering itself instead of the compression.
> >>>>>>>>
> >>>>>>>> Are you OK with that?
> >>>>>>>>
> >>>>>>>> Anthony
> >>>>>>>>
> >>>>>>>> Le 23 mars 2017 00:24, "Remko Popma" <[hidden email]> a
> > écrit :
> >>>>>>>>
> >>>>>>>>
> >>>>>>>>> On Mar 23, 2017, at 1:06, Anthony Maire <[hidden email]
> >
> >>>>>>> wrote:
> >>>>>>>>> Thanks for these answers
> >>>>>>>>>
> >>>>>>>>> @Ralph : that was the kind of idea I had in mind : changing the
> >>>>>>>>> RollingFileManager.asyncExecutor to be a
> > ScheduledThreadPoolExecutor,
> >>>>>>> and
> >>>>>>>>> based on some configuration, submitting task to be executed
> after a
> >>>>>>> random
> >>>>>>>>> delay. However with this kind of approach, special treatment
> > should be
> >>>>>>>> made
> >>>>>>>>> if the manager is stopped with some pending delayed tasks in it.
> >>>>>>>> I'm okay with randomization except for this last bit about
> "special
> >>>>>>>> treatment...". Let's not make it too fancy. If the manager is
> > stopped
> >>>>>>>> before it rolled over, then it didn't roll over, just like it
> works
> >>>>>>>> currently. I don't see the point of adding extra logic to trigger
> a
> >>>>>>>> rollover when the manager is stopped within the randomized time
> > window.
> >>>>>>>>
> >>>>>>>>> @Matt : Cron policy can be a solution, but I don't know how to
> > inject
> >>>>>>> some
> >>>>>>>>> random element in this to make the file roll at midnight + X
> random
> >>>>>>>>> seconds. Since there is a lot of JVM to manage and some of them
> > can be
> >>>>>>>>> moved from a machine to another, I need to have a single
> log4j2.xml
> >>>>>>> file
> >>>>>>>>> for all environments. Moreover, our system administrators are
> >>>>>>> reluctant to
> >>>>>>>>> have something based on a shell-specific feature (such has the
> > $RANDOM
> >>>>>>>>> variable from bash)
> >>>>>>>>>
> >>>>>>>>> Anthony
> >>>>>>>>>
> >>>>>>>>> 2017-03-22 16:31 GMT+01:00 Ralph Goers <
> [hidden email]
> >> :
> >>>>>>>>>
> >>>>>>>>>> These are separate JVMs, so having a single executor would be of
> > no
> >>>>>>> help.
> >>>>>>>>>> I believe the only way to do what you are asking for is to add
> >>>>>>>>>> configuration so that the asynchronous thread has a semi-random
> > delay
> >>>>>>>> when
> >>>>>>>>>> it starts.
> >>>>>>>>>>
> >>>>>>>>>> Ralph
> >>>>>>>>>>
> >>>>>>>>>>> On Mar 22, 2017, at 7:58 AM, Greg Thomas <
> [hidden email]
> >>
> >>>>>>>>>> wrote:
> >>>>>>>>>>>> One common issue we have with that framework (and I assume we
> > can
> >>>>>>> have
> >>>>>>>>>> the
> >>>>>>>>>>>> same with log4j2) is that all of our JVMs (we can have more
> > than 50
> >>>>>>>>>> JVMs on
> >>>>>>>>>>>> the same server in production) roll their file at midnight.
> >>>>>>>>>>>>
> >>>>>>>>>>>> When this happens, the system became often not usable for a
> few
> >>>>>>> seconds
> >>>>>>>>>>>> because of the simultaneous zipping of all the rolled files
> that
> >>>>>>>>>> overload
> >>>>>>>>>>>> the CPU (although zipping is done in a specific background
> > thread).
> >>>>>>>>>>> ISTR that with the most recent versions of log4j, these threads
> > are
> >>>>>>> in a
> >>>>>>>>>>> thread pool so that they are properly shutdown at the right
> > time. I
> >>>>>>>>>> wonder
> >>>>>>>>>>> if it's possible (or could be possible) to somehow inject a
> > thread
> >>>>>>> pool
> >>>>>>>>>> in
> >>>>>>>>>>> to log4j for this rollover, so that for you use case you could
> >>>>>>> inject a
> >>>>>>>>>>> single thread executor, so only one thread is ever compressing
> > at a
> >>>>>>>> time.
> >>>>>>>>>>> Just a thought, anyway,
> >>>>>>>>>>>
> >>>>>>>>>>> Greg
> >>>>>>>>>>>
> >>>>>>>>>>> On 22 March 2017 at 13:47, Anthony Maire <
> [hidden email]
> >>
> >>>>>>>>>> wrote:
> >>>>>>>>>>>> Hi
> >>>>>>>>>>>>
> >>>>>>>>>>>> We are currently using another logging framework in
> production,
> > but
> >>>>>>> I'm
> >>>>>>>>>>>> pushing to change it for log4j2.
> >>>>>>>>>>>>
> >>>>>>>>>>>> One common issue we have with that framework (and I assume we
> > can
> >>>>>>> have
> >>>>>>>>>> the
> >>>>>>>>>>>> same with log4j2) is that all of our JVMs (we can have more
> > than 50
> >>>>>>>>>> JVMs on
> >>>>>>>>>>>> the same server in production) roll their file at midnight.
> >>>>>>>>>>>>
> >>>>>>>>>>>> When this happens, the system became often not usable for a
> few
> >>>>>>> seconds
> >>>>>>>>>>>> because of the simultaneous zipping of all the rolled files
> that
> >>>>>>>>>> overload
> >>>>>>>>>>>> the CPU (although zipping is done in a specific background
> > thread).
> >>>>>>> To
> >>>>>>>>>>>> reduce this effect, we are combining a time based rolling
> policy
> >>>>>>> with a
> >>>>>>>>>>>> sized based policy to zip smaller files, but this is not
> enough
> > to
> >>>>>>> make
> >>>>>>>>>> the
> >>>>>>>>>>>> system fully responsive at midnight.
> >>>>>>>>>>>>
> >>>>>>>>>>>> A pretty cool feature for us to avoid this issue is to have
> the
> >>>>>>>>>> possibility
> >>>>>>>>>>>> when a rolling is triggered because of a time based policy to
> > change
> >>>>>>>>>> file
> >>>>>>>>>>>> immediately, but to wait for a random amount of time (within a
> >>>>>>>>>> configurable
> >>>>>>>>>>>> limit) before starting the compression. This random delay
> should
> >>>>>>> help a
> >>>>>>>>>> lot
> >>>>>>>>>>>> to avoid contention on CPU cycles.
> >>>>>>>>>>>>
> >>>>>>>>>>>> Does log4j2 have something to solve this kind of issue ? If
> not,
> >>>>>>> would
> >>>>>>>>>> you
> >>>>>>>>>>>> accept a pull request for this (I will open a Jira if needed)
> ?
> >>>>>>>>>>>>
> >>>>>>>>>>>> Regards,
> >>>>>>>>>>>> Anthony
> >>>>>>>>>>>>
> >>>>>>>>>>
> >>>>>>>>>> ------------------------------------------------------------
> > ---------
> >>>>>>>>>> To unsubscribe, e-mail: log4j-user-unsubscribe@
> logging.apache.org
> >>>>>>>>>> For additional commands, e-mail: log4j-user-help@logging.
> > apache.org
> >>>>>>>>>>
> >>>>>>>>>>
> >>>>>>>> ------------------------------------------------------------
> > ---------
> >>>>>>>> To unsubscribe, e-mail: [hidden email]
> >>>>>>>> For additional commands, e-mail: log4j-user-help@logging.
> apache.org
> >>>>>>> ------------------------------------------------------------
> ---------
> >>>>>>> To unsubscribe, e-mail: [hidden email]
> >>>>>>> For additional commands, e-mail: log4j-user-help@logging.
> apache.org
> >>>>>>>
> >>>>>>>
> >>>>
> >>>> ---------------------------------------------------------------------
> >>>> To unsubscribe, e-mail: [hidden email]
> >>>> For additional commands, e-mail: [hidden email]
> >>>>
> >>> ---------------------------------------------------------------------
> >>> To unsubscribe, e-mail: [hidden email]
> >>> For additional commands, e-mail: [hidden email]
> >>>
> >>
> >>
> >> ---------------------------------------------------------------------
> >> To unsubscribe, e-mail: [hidden email]
> >> For additional commands, e-mail: [hidden email]
> >>
> >
> > ---------------------------------------------------------------------
> > To unsubscribe, e-mail: [hidden email]
> > For additional commands, e-mail: [hidden email]
>
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: [hidden email]
> For additional commands, e-mail: [hidden email]
>
>
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Compression of rolled files : performance issue when lots of JVMs are using timed based policy

Ralph Goers
I do, but since our code was blatantly copied from Quartz I am not sure how easy it will be to do. If this support is added it should also be submitted to Quartz.  I would look and see how Jenkins. Jenkins seems to be under the MIT license so that should be no problem.

Ralph

> On Mar 27, 2017, at 12:00 AM, Anthony Maire <[hidden email]> wrote:
>
> That's probably why I wasn't able to figure out how you can do this with
> CronTrigerringPolicy :)
> Do you think that adding this random support in cron expression is a better
> solution ?
>
> Regards,
> Anthony
>
> 2017-03-24 18:47 GMT+01:00 Ralph Goers <[hidden email]>:
>
>> I thought CronTriggeringPolicy would handle this but it is based on
>> Quartz’ CronExpression which doesn’t support randomizing fields. I was
>> confused because Jenkins supports this and I had thought it was using
>> Quartz. Apparently not.
>>
>> Ralph
>>
>>
>>> On Mar 24, 2017, at 10:15 AM, Anthony Maire <[hidden email]>
>> wrote:
>>>
>>> Basically we are hosting distributed systems for our clients. So we have
>>> several dozens of JVM per physical host, and several dozens of physical
>>> hosts. Moreover some clients are sometimes moved from one machine to
>>> another so having a single configuration file is a very huge requirement.
>>>
>>> Having the file that rolls precisely at midnight is a nice to have.
>> Having
>>> the rolling that happen a little later because of randomization can be
>>> accepted if it solve the performance issue (which stay pretty short, it's
>>> about 15 seconds during which we can experience a few hundreds of
>>> milliseconds long stalls but this is already too much in our industry )
>>>
>>> Randomization is a common technique for that kind of issue, used in
>>> congestion avoidance in some network protocols for example (including
>>> Ethernet ). Having 2 or 3 jvm that roll at the same time is not a big
>> deal,
>>> we have enough free cpu cycles for that. That's why randomization during
>> a
>>> few minutes seems OK to me : we don't need to annihilate collisions,
>>> greatly reduce them is OK
>>>
>>> Basically I'm open to any solution as long as it can be deployed
>> everywhere
>>> without any OS/shell dependant trick and it does not involve any kind of
>>> per JVM configuration. The patch I submitted is an option, but I'd be
>> glad
>>> to use another option that match these requirements.
>>>
>>> Regards,
>>> Anthony
>>>
>>>
>>> Le 24 mars 2017 15:20, "Remko Popma" <[hidden email]> a écrit :
>>>
>>> Actually, there is already something like this because Log4j2
>> configuration
>>> has some support for scripting. I would prefer to enhance that over
>>> building conditional constructs in the configuration.
>>>
>>> However, having to specify the exact rollover time for individual servers
>>> would result in a much more lengthy and involved configuration.
>>> Randomization is a commonly used technique to get roughly the same result
>>> without the inconvenience of precise configuration. I don't think it is
>>> such a bad idea.
>>>
>>> Sent from my iPhone
>>>
>>>> On Mar 24, 2017, at 19:35, Dominik Psenner <[hidden email]> wrote:
>>>>
>>>> What if a configuration could contain conditional statements? For
>>> instance:
>>>>
>>>> <Config>
>>>>  <Define EnvironmentVariable="Hour" Value="12" />
>>>>  <Define EnvironmentVariable="Minute" Value="0" />
>>>>  <If EnvironmentVariable="JVM" Equals="JVM1">
>>>>      <Define EnvironmentVariable="Minute" Value="0" />
>>>>  </If>
>>>>  <If EnvironmentVariable="JVM" Equals="JVM2">
>>>>      <Define EnvironmentVariable="Minute" Value="1" />
>>>>  </If>
>>>>  <RollingFileAppender>
>>>>      <RollingCondition>
>>>>          <Cron Minute="$Minute" Hour="$Hour" DayOfMonth="*" Month="*"
>>> DayOfWeek="*" />
>>>>      </RollingCondition>
>>>>  </RollingFileAppender>
>>>> </Config>
>>>>
>>>> Cheers
>>>>
>>>>> On 2017-03-24 11:08, Remko Popma wrote:
>>>>> I see what you are saying, but the use case is to have a single
>>> configuration, that is what drives the request.
>>>>>
>>>>> Sent from my iPhone
>>>>>
>>>>>> On Mar 24, 2017, at 17:22, Dominik Psenner <[hidden email]>
>> wrote:
>>>>>>
>>>>>> Hi there,
>>>>>>
>>>>>> Cron proved itself very to be stable and usable over the past years.
>>> FWIW, I would not recommend to introduce a randomization algorithm. An
>>> application that does things random means that the application does
>> things
>>> when nobody expects it to do so. Further it does not solve the problem.
>> One
>>> just needs enough JVMs to roll around at the same time with a randomizer
>>> does not produce large enough values to spread the rolling over a larger
>>> amount of time. The available CPU is then quickly drain out. In my
>> opinion,
>>> it's better to configure the several rollings to be delayed, meaning that
>>> JVM1 rolls at 12:00, JVM2 rolls at 12:01, ...
>>>>>>
>>>>>> Cheers, Dominik
>>>>>>
>>>>>>> On 2017-03-23 15:04, Anthony Maire wrote:
>>>>>>> https://issues.apache.org/jira/browse/LOG4J2-1855
>>>>>>> https://github.com/apache/logging-log4j2/pull/68
>>>>>>>
>>>>>>> Let me know if you want me to do some changes
>>>>>>>
>>>>>>> Regards,
>>>>>>> Anthony
>>>>>>>
>>>>>>>
>>>>>>> 2017-03-23 13:15 GMT+01:00 Anthony Maire <[hidden email]>:
>>>>>>>
>>>>>>>> Ok,  I will open a jira ticket and provide a PR.
>>>>>>>>
>>>>>>>> Thanks for your input.
>>>>>>>>
>>>>>>>> Le 23 mars 2017 13:08, "Remko Popma" <[hidden email]> a
>> écrit :
>>>>>>>>
>>>>>>>>> I see what you mean now. I agree it's better to keep the rollover
>>> concept
>>>>>>>>> to mean file rename and compression that happen in sequence
>>> together. So
>>>>>>>>> the randomization affects when the _sequence_ is triggered, not
>> just
>>> one
>>>>>>>>> part of the sequence. Makes sense.
>>>>>>>>>
>>>>>>>>> Sent from my iPhone
>>>>>>>>>
>>>>>>>>>> On Mar 23, 2017, at 16:28, Anthony Maire <[hidden email]
>>>
>>>>>>>>> wrote:
>>>>>>>>>> Hi Remko
>>>>>>>>>>
>>>>>>>>>> My first idea was to have the rolling that triggers at the
>> expected
>>>>>>>>> time,
>>>>>>>>>> and the compression that will be delayed. That's why I wanted the
>>>>>>>>> delayed
>>>>>>>>>> compression to occur before shutdown since the rolling already
>>> occurred.
>>>>>>>>>>
>>>>>>>>>> But I think that's a bad idea. First, it will lead to "fancy code"
>>> and I
>>>>>>>>>> would like to avoid it too. But the main issue is that this
>> behavior
>>>>>>>>> should
>>>>>>>>>> impact only the time based triggering when combining several
>>> policy. So
>>>>>>>>> the
>>>>>>>>>> code should be related to the triggering policy and not to the
>>> rolling
>>>>>>>>>> strategy.
>>>>>>>>>>
>>>>>>>>>> So the best thing to do is to add some property on the timed base
>>>>>>>>>> triggering policy and let that class handle all the logic and
>> delay
>>> the
>>>>>>>>>> triggering itself instead of the compression.
>>>>>>>>>>
>>>>>>>>>> Are you OK with that?
>>>>>>>>>>
>>>>>>>>>> Anthony
>>>>>>>>>>
>>>>>>>>>> Le 23 mars 2017 00:24, "Remko Popma" <[hidden email]> a
>>> écrit :
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>>> On Mar 23, 2017, at 1:06, Anthony Maire <[hidden email]
>>>
>>>>>>>>> wrote:
>>>>>>>>>>> Thanks for these answers
>>>>>>>>>>>
>>>>>>>>>>> @Ralph : that was the kind of idea I had in mind : changing the
>>>>>>>>>>> RollingFileManager.asyncExecutor to be a
>>> ScheduledThreadPoolExecutor,
>>>>>>>>> and
>>>>>>>>>>> based on some configuration, submitting task to be executed
>> after a
>>>>>>>>> random
>>>>>>>>>>> delay. However with this kind of approach, special treatment
>>> should be
>>>>>>>>>> made
>>>>>>>>>>> if the manager is stopped with some pending delayed tasks in it.
>>>>>>>>>> I'm okay with randomization except for this last bit about
>> "special
>>>>>>>>>> treatment...". Let's not make it too fancy. If the manager is
>>> stopped
>>>>>>>>>> before it rolled over, then it didn't roll over, just like it
>> works
>>>>>>>>>> currently. I don't see the point of adding extra logic to trigger
>> a
>>>>>>>>>> rollover when the manager is stopped within the randomized time
>>> window.
>>>>>>>>>>
>>>>>>>>>>> @Matt : Cron policy can be a solution, but I don't know how to
>>> inject
>>>>>>>>> some
>>>>>>>>>>> random element in this to make the file roll at midnight + X
>> random
>>>>>>>>>>> seconds. Since there is a lot of JVM to manage and some of them
>>> can be
>>>>>>>>>>> moved from a machine to another, I need to have a single
>> log4j2.xml
>>>>>>>>> file
>>>>>>>>>>> for all environments. Moreover, our system administrators are
>>>>>>>>> reluctant to
>>>>>>>>>>> have something based on a shell-specific feature (such has the
>>> $RANDOM
>>>>>>>>>>> variable from bash)
>>>>>>>>>>>
>>>>>>>>>>> Anthony
>>>>>>>>>>>
>>>>>>>>>>> 2017-03-22 16:31 GMT+01:00 Ralph Goers <
>> [hidden email]
>>>> :
>>>>>>>>>>>
>>>>>>>>>>>> These are separate JVMs, so having a single executor would be of
>>> no
>>>>>>>>> help.
>>>>>>>>>>>> I believe the only way to do what you are asking for is to add
>>>>>>>>>>>> configuration so that the asynchronous thread has a semi-random
>>> delay
>>>>>>>>>> when
>>>>>>>>>>>> it starts.
>>>>>>>>>>>>
>>>>>>>>>>>> Ralph
>>>>>>>>>>>>
>>>>>>>>>>>>> On Mar 22, 2017, at 7:58 AM, Greg Thomas <
>> [hidden email]
>>>>
>>>>>>>>>>>> wrote:
>>>>>>>>>>>>>> One common issue we have with that framework (and I assume we
>>> can
>>>>>>>>> have
>>>>>>>>>>>> the
>>>>>>>>>>>>>> same with log4j2) is that all of our JVMs (we can have more
>>> than 50
>>>>>>>>>>>> JVMs on
>>>>>>>>>>>>>> the same server in production) roll their file at midnight.
>>>>>>>>>>>>>>
>>>>>>>>>>>>>> When this happens, the system became often not usable for a
>> few
>>>>>>>>> seconds
>>>>>>>>>>>>>> because of the simultaneous zipping of all the rolled files
>> that
>>>>>>>>>>>> overload
>>>>>>>>>>>>>> the CPU (although zipping is done in a specific background
>>> thread).
>>>>>>>>>>>>> ISTR that with the most recent versions of log4j, these threads
>>> are
>>>>>>>>> in a
>>>>>>>>>>>>> thread pool so that they are properly shutdown at the right
>>> time. I
>>>>>>>>>>>> wonder
>>>>>>>>>>>>> if it's possible (or could be possible) to somehow inject a
>>> thread
>>>>>>>>> pool
>>>>>>>>>>>> in
>>>>>>>>>>>>> to log4j for this rollover, so that for you use case you could
>>>>>>>>> inject a
>>>>>>>>>>>>> single thread executor, so only one thread is ever compressing
>>> at a
>>>>>>>>>> time.
>>>>>>>>>>>>> Just a thought, anyway,
>>>>>>>>>>>>>
>>>>>>>>>>>>> Greg
>>>>>>>>>>>>>
>>>>>>>>>>>>> On 22 March 2017 at 13:47, Anthony Maire <
>> [hidden email]
>>>>
>>>>>>>>>>>> wrote:
>>>>>>>>>>>>>> Hi
>>>>>>>>>>>>>>
>>>>>>>>>>>>>> We are currently using another logging framework in
>> production,
>>> but
>>>>>>>>> I'm
>>>>>>>>>>>>>> pushing to change it for log4j2.
>>>>>>>>>>>>>>
>>>>>>>>>>>>>> One common issue we have with that framework (and I assume we
>>> can
>>>>>>>>> have
>>>>>>>>>>>> the
>>>>>>>>>>>>>> same with log4j2) is that all of our JVMs (we can have more
>>> than 50
>>>>>>>>>>>> JVMs on
>>>>>>>>>>>>>> the same server in production) roll their file at midnight.
>>>>>>>>>>>>>>
>>>>>>>>>>>>>> When this happens, the system became often not usable for a
>> few
>>>>>>>>> seconds
>>>>>>>>>>>>>> because of the simultaneous zipping of all the rolled files
>> that
>>>>>>>>>>>> overload
>>>>>>>>>>>>>> the CPU (although zipping is done in a specific background
>>> thread).
>>>>>>>>> To
>>>>>>>>>>>>>> reduce this effect, we are combining a time based rolling
>> policy
>>>>>>>>> with a
>>>>>>>>>>>>>> sized based policy to zip smaller files, but this is not
>> enough
>>> to
>>>>>>>>> make
>>>>>>>>>>>> the
>>>>>>>>>>>>>> system fully responsive at midnight.
>>>>>>>>>>>>>>
>>>>>>>>>>>>>> A pretty cool feature for us to avoid this issue is to have
>> the
>>>>>>>>>>>> possibility
>>>>>>>>>>>>>> when a rolling is triggered because of a time based policy to
>>> change
>>>>>>>>>>>> file
>>>>>>>>>>>>>> immediately, but to wait for a random amount of time (within a
>>>>>>>>>>>> configurable
>>>>>>>>>>>>>> limit) before starting the compression. This random delay
>> should
>>>>>>>>> help a
>>>>>>>>>>>> lot
>>>>>>>>>>>>>> to avoid contention on CPU cycles.
>>>>>>>>>>>>>>
>>>>>>>>>>>>>> Does log4j2 have something to solve this kind of issue ? If
>> not,
>>>>>>>>> would
>>>>>>>>>>>> you
>>>>>>>>>>>>>> accept a pull request for this (I will open a Jira if needed)
>> ?
>>>>>>>>>>>>>>
>>>>>>>>>>>>>> Regards,
>>>>>>>>>>>>>> Anthony
>>>>>>>>>>>>>>
>>>>>>>>>>>>
>>>>>>>>>>>> ------------------------------------------------------------
>>> ---------
>>>>>>>>>>>> To unsubscribe, e-mail: log4j-user-unsubscribe@
>> logging.apache.org
>>>>>>>>>>>> For additional commands, e-mail: log4j-user-help@logging.
>>> apache.org
>>>>>>>>>>>>
>>>>>>>>>>>>
>>>>>>>>>> ------------------------------------------------------------
>>> ---------
>>>>>>>>>> To unsubscribe, e-mail: [hidden email]
>>>>>>>>>> For additional commands, e-mail: log4j-user-help@logging.
>> apache.org
>>>>>>>>> ------------------------------------------------------------
>> ---------
>>>>>>>>> To unsubscribe, e-mail: [hidden email]
>>>>>>>>> For additional commands, e-mail: log4j-user-help@logging.
>> apache.org
>>>>>>>>>
>>>>>>>>>
>>>>>>
>>>>>> ---------------------------------------------------------------------
>>>>>> To unsubscribe, e-mail: [hidden email]
>>>>>> For additional commands, e-mail: [hidden email]
>>>>>>
>>>>> ---------------------------------------------------------------------
>>>>> To unsubscribe, e-mail: [hidden email]
>>>>> For additional commands, e-mail: [hidden email]
>>>>>
>>>>
>>>>
>>>> ---------------------------------------------------------------------
>>>> To unsubscribe, e-mail: [hidden email]
>>>> For additional commands, e-mail: [hidden email]
>>>>
>>>
>>> ---------------------------------------------------------------------
>>> To unsubscribe, e-mail: [hidden email]
>>> For additional commands, e-mail: [hidden email]
>>
>>
>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: [hidden email]
>> For additional commands, e-mail: [hidden email]
>>
>>



---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Loading...