chocolatey / choco

Chocolatey - the package manager for Windows
https://chocolatey.org
Other
10.21k stars 896 forks source link

log4net:WARN Cannot RollFile #2310

Open LeszekKalibrate opened 3 years ago

LeszekKalibrate commented 3 years ago

What You Are Seeing?

ERROR: The running command stopped because the preference variable "ErrorActionPreference" or common parameter is set to Stop: log4net:WARN Cannot RollFile [C:\ProgramData\chocolatey\logs\choco.summary.1.log] -> [C:\ProgramData\chocolatey\logs\choco.summary.2.log]. Source does not exist
at <ScriptBlock>, C:\ProgramData\chocolatey\lib\deployment\tools\lib\choco.ps1: line 74
at Upgrade-ChocoPackages, C:\ProgramData\chocolatey\lib\deployment\tools\lib\choco.ps1: line 70
at <ScriptBlock>, C:\ProgramData\chocolatey\lib\deployment\tools\chocolateyinstall.ps1: line 68
at <ScriptBlock>, C:\ProgramData\chocolatey\helpers\chocolateyScriptRunner.ps1: line 49
at <ScriptBlock>, <No file>: line 1
2020-08-03 11:44:58,267 5076 [WARN ] -
Chocolatey upgraded 0/1 packages. 1 packages failed.
See the log for details (C:\ProgramData\chocolatey\logs\chocolatey.log).
2020-08-03 11:44:58,267 5076 [INFO ] -
2020-08-03 11:44:58,267 5076 [ERROR] - Failures
2020-08-03 11:44:58,267 5076 [ERROR] - - deployment (exited -1) - Error while running 'C:\ProgramData\chocolatey\lib\deployment\tools\chocolateyinstall.ps1'.

What is Expected?

No error, Log4NET should find the file and continue logging.

How Did You Get This To Happen? (Steps to Reproduce)

Deployment script to install a lot of software and do db migration that's a lot of log information, over 20MB.

Output Log

Full Log Output

~~~sh 2020-08-03 11:42:46,781 5076 [DEBUG] - XmlConfiguration is now operational 2020-08-03 11:42:46,875 5076 [INFO ] - ============================================================ 2020-08-03 11:42:47,172 5076 [INFO ] - Chocolatey v0.10.15 2020-08-03 11:42:47,187 5076 [DEBUG] - Chocolatey is running on Windows v 6.3.9600.0 ... 2020-08-03 11:47:25,986 1300 [WARN ] - Chocolatey upgraded 1/1 packages. See the log for details (C:\ProgramData\chocolatey\logs\chocolatey.log). 2020-08-03 11:47:25,986 1300 [DEBUG] - Sending message 'PostRunMessage' out if there are subscribers... 2020-08-03 11:47:25,986 1300 [DEBUG] - Exiting with 0 ~~~

Issue is knows for Log4NET for years https://issues.apache.org/jira/browse/LOG4NET-82

Is it possible to override the log file size? It is set to 1024102410 in code. https://github.com/chocolatey/choco/blob/af3e8c9577ed29d7572581418a8274fd6ce7709b/src/chocolatey/infrastructure/logging/Log4NetAppenderConfiguration.cs#L230

LeszekKalibrate commented 3 years ago

It might be not size issue related, as the summary log file are not big. Why it has Exclusive, not Minimal lock? https://github.com/chocolatey/choco/blob/af3e8c9577ed29d7572581418a8274fd6ce7709b/src/chocolatey/infrastructure/logging/Log4NetAppenderConfiguration.cs#L246

LeszekKalibrate commented 1 year ago

ERROR: The running command stopped because the preference variable "ErrorActionPreference" or common parameter is set to Stop: log4net:ERROR RollingFileAppender: INTERNAL ERROR. Append is False but OutputFile [C:\ProgramData\chocolatey\logs\choco.summary.log] already exists.