freeswitch log rotation bug

[remdragon]

Describe the bug

When a fixed # of freeswitch logs is configured, if one of the files is missing because an overzealous sysadmin deleted some, then the log rotation doesn't complete. You can end up with a gigantic freeswitch.log that fills up the disk and shuts down freeswitch when it runs out of space.

To Reproduce

Steps to reproduce the behavior:

1. Using this example configuration...

root@pbx1:/var/log/freeswitch# cat /etc/freeswitch/autoload_configs/logfile.conf.xml
<configuration name="logfile.conf" description="File Logging">
  <settings>
   <param name="rotate-on-hup" value="true"/>
  </settings>
  <profiles>
    <profile name="default">
      <settings>
        <param name="rollover" value="1048576000"/>
                <param name="maximum-rotate" value="32"/>
        <param name="uuid" value="true" />
      </settings>
      <mappings>
        <map name="all" value="console,debug,info,notice,warning,err,crit,alert"/>
      </mappings>
    </profile>
  </profiles>
</configuration>

2. delete one of the files (notice freeswitch.log.4 is missing):

root@pbx1:/var/log/freeswitch# ls -al
total 5864864
drwxrwx--- 4 www-data www-data 4096 Aug 2 12:31 .
drwxr-xr-x 9 root root 4096 Aug 2 00:00 ..
drwxr-x--- 2 www-data www-data 4096 Oct 7 2021 cdr-csv
-rw-r--r-- 1 www-data www-data 49 Oct 12 2021 freeswitch.history
-rw-rw---- 1 www-data www-data 222980853 Aug 2 12:32 freeswitch.log
-rw-rw---- 1 www-data www-data 8051169 Aug 2 06:24 freeswitch.log.1
-rw-r--r-- 1 www-data www-data 0 Aug 1 13:18 freeswitch.log.10
-rw-r--r-- 1 www-data www-data 0 Aug 1 13:18 freeswitch.log.11
-rw-r--r-- 1 www-data www-data 0 Aug 1 13:18 freeswitch.log.12
-rw-r--r-- 1 www-data www-data 0 Aug 1 13:18 freeswitch.log.13
-rw-r--r-- 1 www-data www-data 0 Aug 1 13:18 freeswitch.log.14
-rw-r--r-- 1 www-data www-data 0 Aug 1 13:18 freeswitch.log.15
-rw-r--r-- 1 www-data www-data 0 Aug 1 13:17 freeswitch.log.16
-rw-r--r-- 1 www-data www-data 0 Aug 1 13:18 freeswitch.log.17
-rw-r--r-- 1 www-data www-data 0 Aug 1 13:17 freeswitch.log.18
-rw-r--r-- 1 www-data www-data 0 Aug 1 13:17 freeswitch.log.19
-rw-rw---- 1 www-data www-data 379722153 Aug 2 00:00 freeswitch.log.2
-rw-r--r-- 1 www-data www-data 0 Aug 1 13:17 freeswitch.log.20
-rw-r--r-- 1 www-data www-data 0 Aug 1 13:17 freeswitch.log.21
-rw-r--r-- 1 www-data www-data 0 Aug 1 13:17 freeswitch.log.22
-rw-rw---- 1 www-data www-data 5394140631 Aug 1 13:18 freeswitch.log.3
-rw-r--r-- 1 www-data www-data 0 Aug 1 13:18 freeswitch.log.5
-rw-r--r-- 1 www-data www-data 0 Aug 1 13:18 freeswitch.log.6
-rw-r--r-- 1 www-data www-data 0 Aug 1 13:18 freeswitch.log.7
-rw-r--r-- 1 www-data www-data 0 Aug 1 13:18 freeswitch.log.8
-rw-r--r-- 1 www-data www-data 0 Aug 1 13:18 freeswitch.log.9
-rw-r--r-- 1 root root 0 Aug 1 13:17 freeswitch.oog.13
-rw-rw---- 1 www-data www-data 679908 Jul 12 15:49 freeswitch.xml.fsxml
drwxr-x--- 2 www-data www-data 4096 May 16 12:12 xml_cdr

3. open fs_cli
4. fsctl send_sighup

freeswitch@pbx1> fsctl send_sighup
+OK

2022-08-02 12:36:23.740520 94.47% [CRIT] mod_logfile.c:164 Error renaming log from /var/log/freeswitch/freeswitch.log.4 to /var/log/freeswitch/freeswitch.log.5 [No such file or directory]

5. Observe log folder, now both .4 and .5 is missing because the log rotation stopped on the missing file.

root@pbx1:/var/log/freeswitch# ls -al
total 5867496
drwxrwx--- 4 www-data www-data 4096 Aug 2 12:36 .
drwxr-xr-x 9 root root 4096 Aug 2 00:00 ..
drwxr-x--- 2 www-data www-data 4096 Oct 7 2021 cdr-csv
-rw-r--r-- 1 www-data www-data 49 Oct 12 2021 freeswitch.history
-rw-rw---- 1 www-data www-data 225676996 Aug 2 12:36 freeswitch.log
-rw-rw---- 1 www-data www-data 8051169 Aug 2 06:24 freeswitch.log.1
-rw-r--r-- 1 www-data www-data 0 Aug 1 13:18 freeswitch.log.10
-rw-r--r-- 1 www-data www-data 0 Aug 1 13:18 freeswitch.log.11
-rw-r--r-- 1 www-data www-data 0 Aug 1 13:18 freeswitch.log.12
-rw-r--r-- 1 www-data www-data 0 Aug 1 13:18 freeswitch.log.13
-rw-r--r-- 1 www-data www-data 0 Aug 1 13:18 freeswitch.log.14
-rw-r--r-- 1 www-data www-data 0 Aug 1 13:18 freeswitch.log.15
-rw-r--r-- 1 www-data www-data 0 Aug 1 13:18 freeswitch.log.16
-rw-r--r-- 1 www-data www-data 0 Aug 1 13:17 freeswitch.log.17
-rw-r--r-- 1 www-data www-data 0 Aug 1 13:18 freeswitch.log.18
-rw-r--r-- 1 www-data www-data 0 Aug 1 13:17 freeswitch.log.19
-rw-rw---- 1 www-data www-data 379722153 Aug 2 00:00 freeswitch.log.2
-rw-r--r-- 1 www-data www-data 0 Aug 1 13:17 freeswitch.log.20
-rw-r--r-- 1 www-data www-data 0 Aug 1 13:17 freeswitch.log.21
-rw-r--r-- 1 www-data www-data 0 Aug 1 13:17 freeswitch.log.22
-rw-r--r-- 1 www-data www-data 0 Aug 1 13:17 freeswitch.log.23
-rw-rw---- 1 www-data www-data 5394140631 Aug 1 13:18 freeswitch.log.3
-rw-r--r-- 1 www-data www-data 0 Aug 1 13:18 freeswitch.log.6
-rw-r--r-- 1 www-data www-data 0 Aug 1 13:18 freeswitch.log.7
-rw-r--r-- 1 www-data www-data 0 Aug 1 13:18 freeswitch.log.8
-rw-r--r-- 1 www-data www-data 0 Aug 1 13:18 freeswitch.log.9
-rw-rw---- 1 www-data www-data 679908 Jul 12 15:49 freeswitch.xml.fsxml
drwxr-x--- 2 www-data www-data 4096 May 16 12:12 xml_cdr

Expected behavior

If freeswitch.log.4 (for example) is missing, it should continue processing the rest of the rotations.

Package version or git hash
Distributor ID: Debian
Description: Debian GNU/Linux 10 (buster)
Release: 10
Codename: buster
FreeSWITCH Version 1.10.7-release-19-883d2cb662~64bit (-release-19-883d2cb662 64bit)

Trace logs
Provide freeswitch logs w/ DEBUG and UUID logging enabled

2022-08-02 12:36:23.740520 94.47% [CRIT] mod_logfile.c:164 Error renaming log from /var/log/freeswitch/freeswitch.log.4 to /var/log/freeswitch/freeswitch.log.5 [No such file or directory]

[remdragon]

quick fix:

change line 166 from:

				goto end;

to:

				if (errno != ENOENT)
					goto end;

git diff of proposed change:

diff --git a/src/mod/loggers/mod_logfile/mod_logfile.c b/src/mod/loggers/mod_logfile/mod_logfile.c
index 4dc3c6a7e8..ff951b46b5 100644
--- a/src/mod/loggers/mod_logfile/mod_logfile.c
+++ b/src/mod/loggers/mod_logfile/mod_logfile.c
@@ -163,7 +163,8 @@ static switch_status_t mod_logfile_rotate(logfile_profile_t *profile)
                        if ((status = switch_file_rename(from_filename, to_filename, pool)) != SWITCH_STATUS_SUCCESS) {
                                switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_CRIT, "Error renaming log from %s to %s [%s]\n",
                                                                  from_filename, to_filename, strerror(errno));
-                               goto end;
+                               if (errno != ENOENT)
+                                       goto end;
                        }
                }

[andywolk]

PRs are welcome!

[remdragon]

#1834