Logs do not rotate when they hit the max Mb limit

[mmascher]

Describe the bug
Since a long time CMS has been experiencing issues with log rotation and disk filling up. Basically logs in log/group_* keeps growing until frontends just fills up the disk.

To Reproduce
Reduce the max_mbytes="10.0" param to a small number and verify logs are not rotated.

Info (please complete the following information):

• Priority: high
• Stakeholders: CMS
• Components: frontend

[mambelli]

@mmascher Changes in a0a3413 are incorrect.
self.rollover_not_before is coming from min_days=... />, not max_days. Did you set min_days in your configuration? Default is 0. Leave min_days blank or set it to 0.
For the timed rotation max_days should be used.
If you did not set min_days or the rotation is not performed after min_days then there is a bug somewhere else.

[mmascher]

@mambelli min_days is set to 3 days. What is the desired logic?

My thinking was that "size related rotation" has to be performed no matter what. But now that I think a bit more, I see why it is "wait at least min_days before performing size rotation". This means this is not working:

https://github.com/mmascher/glideinwms/blob/a0a341394ba6527a80523072251faae45f2de7b4/lib/logSupport.py#L140-L147

rollover_not_before keeps getting pushed because we keep putting stuff in the logs, and then we get os.stat(filename)[stat.ST_MTIME].

I suppose what we need for begin_interval_time is not the last modification time of the current log, but the last modification time of the "latest rotated logfile". Something like glob(str(filename)+*), then get modification times, and take the most recent.

I actually wonder if "time based rotation" ever worked. Looking at the code before the structlog changes:

https://github.com/mmascher/glideinwms/blob/98b967957e0fa2cc46aa61dcad0061fb8ab69e30/lib/logSupport.py#L84-L171

minDays was always ignored, and maxDays suffer for the "rotating window" issue I just described if you take the last modification time.

[mmascher]

Alternatively we could just use access time instead of modification time:

[mmascher@vocms0804 gwms-frontend]$ stat /var/log/gwms-frontend/group_local_users/local_users.err.log
  File: /var/log/gwms-frontend/group_local_users/local_users.err.log
  Size: 797592    	Blocks: 1568       IO Block: 4096   regular file
Device: fc10h/64528d	Inode: 18613289    Links: 1
Access: (0644/-rw-r--r--)  Uid: ( 1001/frontend)   Gid: ( 1006/frontend)
Context: system_u:object_r:var_log_t:s0
Access: 2024-11-11 05:19:14.721352019 +0100
Modify: 2024-11-11 09:48:13.883773817 +0100
Change: 2024-11-11 09:48:13.883773817 +0100
 Birth: 2024-11-11 05:19:14.721352019 +0100
[mmascher@vocms0804 gwms-frontend]$ python3
Python 3.9.18 (main, Oct  4 2024, 00:00:00) 
[GCC 11.4.1 20231218 (Red Hat 11.4.1-3)] on linux
Type "help", "copyright", "credits" or "license" for more information.
>>> import os
>>> os.stat("/var/log/gwms-frontend/group_local_users/local_users.err.log")
os.stat_result(st_mode=33188, st_ino=18613289, st_dev=64528, st_nlink=1, st_uid=1001, st_gid=1006, st_size=797592, st_atime=1731298754, st_mtime=1731314893, st_ctime=1731314893)
>>> 
[mmascher@vocms0804 gwms-frontend]$ date -d @1731298754
Mon Nov 11 05:19:14 AM CET 2024
[mmascher@vocms0804 gwms-frontend]$ date -d @1731314893
Mon Nov 11 09:48:13 AM CET 2024

Apparently we can't cet the birthtime in linux, which I find very strange: https://stackoverflow.com/questions/14842195/how-to-get-file-creation-date-time-in-bash-debian