dateFile appender "daysToKeep" not working

[Shinapp]

#806
Problem seems still exists fir log4js 4.0.2

I have changed local time to test:

1. File not rolled when alwaysIncludePattern set to false
2. Old files not being removed after the "daysToKeep"

├─┬ log4js@4.0.2
│ ├── date-format@2.0.0
│ ├─┬ debug@3.2.6
│ │ └── ms@2.1.1
│ ├── flatted@2.0.0
│ ├── rfdc@1.1.2
│ └─┬ streamroller@1.0.1
│ ├── async@2.6.1 deduped
│ ├── date-format@2.0.0 deduped
│ ├── debug@3.2.6 deduped
│ ├── fs-extra@7.0.1 deduped
│ └── lodash@4.17.11 deduped

node v11.5.0

[GanjuV]

daysToKeep is working even if you set alwaysIncludePattern to false in version 4.0.0.

[nomiddlename]

@Shinapp could you post your log4js config, please? Something that might be the cause is that log4js only checks the date/time when you write something - so you have to log something after you change the date on your system, or nothing will happen.

[Shinapp]

@nomiddlename Yes, I have logged something.
Attached my log.config

{
"appenders": {
"infoLog" : {
"type": "dateFile",
"filename": "./logs/simpleTester.log",
"alwaysIncludePattern": true,
"pattern": "yyyyMMdd",
"keepFileExt": false,
"daysToKeep": 1,
"layout": {
"type": "pattern",
"pattern": "[%d] [%-5p] - %m"
}
},
"consoleLog" : {
"type": "console",
"layout": {
"type": "pattern",
"pattern": "[%d] [%-5p] - %m"
}
},
"debugLog" : {
"type": "dateFile",
"filename": "./logs/Debug_simpleTester.log",
"alwaysIncludePattern": true,
"pattern": "yyyyMMdd",
"keepFileExt": false,
"daysToKeep": "10",
"layout": {
"type": "pattern",
"pattern": "[%d] [%-5p] - %m"
}
},
"info": {
"type": "logLevelFilter", "level": "info", "appender":"infoLog"
},
"debug": {
"type": "logLevelFilter", "level": "debug", "appender":"debugLog"
},
"console": {
"type": "logLevelFilter", "level": "all", "appender":"consoleLog"
}
},
"categories": {
"default": {"appenders": ["info", "debug"], "level": "all"},
"test": {"appenders": ["console"], "level": "all"}
}
}

log4js.configure('./config/log.config')
var logger = log4js.getLogger('default')

[nomiddlename]

We made some fixes to date file rotation in 4.2.0, could you try again and see if it fixed your problem?

[Shinapp]

The problem still persist. I am using log4js@4.3.0 .

[utyongu]

I have the same problem.

Windows 7
log4js 4.4.0

[nomiddlename]

Hey @Shinapp - are you still having this problem? Are you on windows too? I'm just trying to work out what may be the cause, date file rotation seems to work fine on my mac and for other people.

[Shinapp]

I still have the problem. I tried the code on mac, linux and window.
Seems the problem is in the rolling condition:
streamroller/lib/RollingFileWriteStream.js line:122
_shouldRoll(callback) { debug(in _shouldRoll, pattern = ${this.options.pattern}, currentDate = ${this.state.currentDate}, now = ${newNow()}); if (this.options.pattern && (format(this.options.pattern, this.state.currentDate) !== format(this.options.pattern, newNow()))) { this._roll({isNextPeriod: true}, callback); return; }

The condition is always false and the cleaning mechanism is not triggered.
I tried hard code the condition to true and it is work.

[nomiddlename]

Possibly related to #909

[nomiddlename]

There were a lot of fixes for file rotation in log4js 5.x - please give log4js@5.1.0 a try and let me know if the problem still exists.

[Shinapp]

Thank you for your reply but seems the problem still exists. Thank you.

├─┬ log4js@5.1.0
│ ├── date-format@2.1.0
│ ├─┬ debug@4.1.1
│ │ └── ms@2.1.2
│ ├── flatted@2.0.1
│ ├── rfdc@1.1.4
│ └─┬ streamroller@2.1.0
│ ├── date-format@2.1.0 deduped
│ ├─┬ debug@4.1.1
│ │ └── ms@2.1.2
│ └─┬ fs-extra@8.1.0
│ ├── graceful-fs@4.2.1 deduped
│ ├─┬ jsonfile@4.0.0
│ │ └── graceful-fs@4.2.1 deduped
│ └── universalify@0.1.2

[mariuswang007]

@Shinapp agree with you. the issue still exists in log4js@5.1.0
@nomiddlename I changed just one line and it seems worked, just for your reference
--streamroller V2.1.0
--RollingFileWriteStream.js
-- line 145:
-- before: this.state.currentDate !== format(this.options.pattern, newNow())
-- after: (this.state.currentDate !== format(this.options.pattern, newNow()) || this.options.numToKeep > 0)

[nomiddlename]

@Shinapp I think your problem is related to the pattern you're using: "yyyyMMdd" maps to all digits, which the code thinks is a file index instead of a date. As a workaround, or to test this out, try using "yyyy-MM-dd" as the pattern. I should have a fix for this issue in the next few days.

@mariuswang007 I'm not sure that your issue is the same, if changing that line fixed it. Could you post your log4js config, please?

[Shinapp]

@Shinapp I think your problem is related to the pattern you're using: "yyyyMMdd" maps to all digits, which the code thinks is a file index instead of a date. As a workaround, or to test this out, try using "yyyy-MM-dd" as the pattern. I should have a fix for this issue in the next few days.

@mariuswang007 I'm not sure that your issue is the same, if changing that line fixed it. Could you post your log4js config, please?

Tried but fail. I have created lots of log file named "filename,log.2019-10-17" etc.

[Shinapp]

@Shinapp agree with you. the issue still exists in log4js@5.1.0
@nomiddlename I changed just one line and it seems worked, just for your reference
--streamroller V2.1.0
--RollingFileWriteStream.js
-- line 145:
-- before: this.state.currentDate !== format(this.options.pattern, newNow())
-- after: (this.state.currentDate !== format(this.options.pattern, newNow()) || this.options.numToKeep > 0)

this.options.numToKeep <-- this is related to the config daysToKeep exist
What it means is make the dateChange flag to always true (if daysToKeep is applied in the config)

[nomiddlename]

@Shinapp could you post some step-by-step instructions on how you're testing this, please? I'm having trouble reproducing the issue. Ideally, if you could include the code you're using as well, that would be great.

[Shinapp]

1. I have a script do some simple log such as logger.info('Server Start')
2. Run the script by 'node <script.js>'
3. Stop the script by SIGKILL
4. Open the macOS 'Date & Time Preference', uncheck the 'Automatic set time'
5. Adjust the day, usually one day after

Repeat 2-5

Suppose whenever a new log file generated will trigger the housekeeping.

[nomiddlename]

With alwaysIncludePattern set, it will always create a new file if the date is different - but that won't trigger clean up of the old ones until the day changes. Does that describe what you're seeing? New log file created, but the old ones stay there?

[Shinapp]

With alwaysIncludePattern set, it will always create a new file if the date is different - but that won't trigger clean up of the old ones until the day changes. Does that describe what you're seeing? New log file created, but the old ones stay there?

Yes, "New log file created, but the old ones stay there", but I expect the old ones clean up after the day passes the larger than daysToKeep.

[nomiddlename]

It won't clean up old files on startup, only when the day changes if it is running. Maybe try changing the date without killing the script, to see if that does what you expect it to do?

[Shinapp]

Seems the problem is solved. I am currently using log4js@5.2.1

[Shinapp]

It won't clean up old files on startup, only when the day changes if it is running. Maybe try changing the date without killing the script, to see if that does what you expect it to do?

This is really the situation I facing. I tried to run on an express services and get the expected behaviour you mentioned.

However, when I running a small script that has no date change during the script running (on cron), it does not clean up old files on startup (or termination)

Is there a way to improve my script or it is a feature request?

P.S. I am running cron jobs and I hope log files will be clean up everyday.

[nomiddlename]

I think the behaviour you describe would be easier to do by adding the clean up to your cron job script. I'm going to close this issue.