You are viewing a plain text version of this content. The canonical link for it is here.
Posted to log4j-dev@logging.apache.org by "Georg Friedrich (JIRA)" <ji...@apache.org> on 2017/01/02 13:27:58 UTC

[jira] [Comment Edited] (LOG4J2-1653) CronTriggeringPolicy uses wrong naming and produces NPE

    [ https://issues.apache.org/jira/browse/LOG4J2-1653?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15792863#comment-15792863 ] 

Georg Friedrich edited comment on LOG4J2-1653 at 1/2/17 1:27 PM:
-----------------------------------------------------------------

Hi Ralph,

thank you for taking a look at it.
Even though I can test you code not before next week, I checked the changes you made and I have found some issues that might still arise with it (to say it again: I didn't execute your code - I just took a look into it).
The following things look weird to me:
* There is a reason that "getTimeBefore" was not implemented in Quartz as it can't be easily implemented. Your solution will only work for some situations (even though these are the mainly appearing ones). Imagine the following cron expression: 0 0 35/10 * * *
This expression would be true on the minutes 35, 45 and 55 on every hour. As you are expecting that all intervals have the same size, you would get some problems here. E.g. when it's "10:30 am" you would calculate 35 and 45 as the next execution minutes. Then you would subtract  the differenct from the current time (\-> 10:20 am) and then calculating the next valid time (\-> 10:35 am). This is obviously not the expected time of "9:55 am".
* You didn't remove the "triggeringPolicy.initialize(this)"-line from "setTriggeringPolicy". This is problematic for the following reasons:
** "triggeringPolicy.initialize(this)" can still be called multiple times as it is used in "setTriggeringPolicy(...)" and in the "initialize()" method which results in multiple executions of the same trigger.
** "triggeringPolicy.initialize(this)" might get called in "setTriggeringPolicy" even though "compareAndSet" fails. You should make sure that "compareAndSet" was executed successfully before changing any additional stuff that you've just added (those new lifecycle lines).

I think I've also found an issue for the changes you made for LOG4J-1649. But I will add the comment over there.


was (Author: gfriedrich):
Hi Ralph,

thank you for taking a look at it.
Even though I can test you code not before next week, I checked the changes you made and I have found some issues that might still arise with it (to say it again: I didn't execute your code - I just took a look into it).
The following things look weird to me:
* There is a reason that "getTimeBefore" was not implemented in Quartz as it can't be easily implemented. Your solution will only work for some situations (even though these are the mainly appearing ones). Imagine the following cron expression: 0 0 35/10 * * *
This expression would be true on the minutes 35, 45 and 55 on every hour. As you are expecting that all intervals have the same size, you would get some problems here. E.g. when it's "10:30 am" you would calculate 35 and 45 as the next execution minutes. Then you would subtract  the differenct from the current time (-> 10:20 am) and then calculating the next valid time (-> 10:35 am). This is obviously not the expected time of "9:55 am".
* You didn't remove the "triggeringPolicy.initialize(this)"-line from "setTriggeringPolicy". This is problematic for the following reasons:
** "triggeringPolicy.initialize(this)" can still be called multiple times as it is used in "setTriggeringPolicy(...)" and in the "initialize()" method which results in multiple executions of the same trigger.
** "triggeringPolicy.initialize(this)" might get called in "setTriggeringPolicy" even though "compareAndSet" fails. You should make sure that "compareAndSet" was executed successfully before changing any additional stuff that you've just added (those new lifecycle lines).

I think I've also found an issue for the changes you made for LOG4J-1649. But I will add the comment over there.

> CronTriggeringPolicy uses wrong naming and produces NPE
> -------------------------------------------------------
>
>                 Key: LOG4J2-1653
>                 URL: https://issues.apache.org/jira/browse/LOG4J2-1653
>             Project: Log4j 2
>          Issue Type: Bug
>    Affects Versions: 2.7
>            Reporter: Georg Friedrich
>            Assignee: Ralph Goers
>            Priority: Critical
>             Fix For: 2.8
>
>         Attachments: ConfigurationScheduler.patch, CronTriggeringPolicy.patch
>
>
> After having worked on LOG4J2-1649 I found another serious issue in combination with the CronTriggeringPolicy.
> The policy has some very weird behaviour when it comes to naming rolled over files and also creates a NPE on specific configurations.
> The following is broken:
> * when using "evaluateOnStartup" a NPE is the result of an immediate rollover
> * when no rollover is happing at startup the first rollover produces a file that uses the time of the rollover (e.g. rollover is happening at midnight 2010-05-05 producing a rolled over file named log-2010-05-05)
> * but it becomes worse: all files after the first rollover are named using a date of the "previous rollover date minus a second" - when using the previous example this results in:
> ** first rollover happening at midnight 2010-05-05, resulting in file log-2010-05-05
> ** next rollover happening at 2010-05-06, resulting in file log-2010-05-04
> ** next rollover happening at 2010-05-07, resulting in file log-2010-05-05 again (!) so the previously saved file gets removed!
> I would expect the file to be named after the content it contains. E.g. a file rolled over at 2010-05-05 should be named log-2010-05-04 as it contains all the data of the 2010-05-04.
> So I decided to write a patch for those problems too (again the sources of Log4J2 2.7 were used). Unfortunately I needed a method to calculate the last cron date. The CronExpression class has such a method ("getTimeBefore") but nobody implemented this one since years.
> The only quick solution I found: I used another 3rd party library to fix this called cronutils. The solution I wrote uses the latest version of this library which now only supports Java 8.
> My guess is that you don't want Log4J2 to only support Java 8 - if this is the case you will have to use a different library/version or whatever to be able to calculate the last cron date.
> This patch should also fix the following bugs: LOG4J2-1640, LOG4J2-1621, LOG4J2-1487, LOG4J2-1474 (and maybe even more - I didn't feel like searching the whole Jira ;-) )



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org