Bug 757311 - logrotate.d can't restart proftpd
Summary: logrotate.d can't restart proftpd
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Fedora
Classification: Fedora
Component: proftpd
Version: 15
Hardware: i386
OS: Linux
unspecified
low
Target Milestone: ---
Assignee: Matthias Saou
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2011-11-26 11:23 UTC by customercare
Modified: 2012-03-08 21:22 UTC (History)
2 users (show)

Fixed In Version: proftpd-1.3.4a-5.fc15
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2012-03-08 21:22:08 UTC
Type: ---
Embargoed:


Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
ProFTPD 3724 0 None None None Never

Description customercare 2011-11-26 11:23:46 UTC
Description of problem:

The logrotate script for proftpd uses :

test -f /var/lock/subsys/proftpd && /usr/bin/killall -HUP proftpd || :

to reload the daemon. This does not work ( see below ) . The Systemd is not able to restart/reload proftpd this way. This may be caused by a bug in the proftpd init script as mentioned: 

"/var/run/proftpd/proftpd.pid does not exist"

The adhoc solution was to switch to a full proftpd restart in the logrotate script : 

test -f /var/lock/subsys/proftpd && /etc/init.d/proftpd try-restart || :

This works flawless now since one week. 


Version-Release number of selected component (if applicable):

1.3.4

How reproducible:

run logrotate and proftpd together
  
Actual results:

Nov 16 03:06:02 c1 proftpd[1441]: 83.246.67.243 - received SIGHUP -- master server reparsing configuration file
Nov 16 03:06:03 c1 systemd[1]: PID 1441 read from file /var/run/proftpd/proftpd.pid does not exist. Your service or init script might be broken.
Nov 16 03:06:03 c1 systemd[1]: proftpd.service: main process exited, code=exited, status=127  

Expected results:

a clean restart of proftpd after logrotate is done.


Here is the ADHOC FIX : 

# cat /etc/logrotate.d/proftpd
/var/log/proftpd/*.log /var/log/xferlog {
    compress
    missingok
    notifempty
    sharedscripts
    postrotate
        test -f /var/lock/subsys/proftpd && /etc/init.d/proftpd try-restart || :
    endscript
}

Comment 1 Paul Howarth 2011-11-28 09:45:25 UTC
I'm struggling to reproduce this. I've tried running "/usr/bin/killall -HUP proftpd" on a Fedora 15 VM and I get the "reparsing configuration file" message in the logs but it otherwise carries on as normal.

Regarding the ad-hoc fix, that particular change isn't good going forward as from Fedora 16 we're using a native systemd unit file and the SysV initscript is no longer shipped. I have a proftpd server running on F-16 and its logs are being rotated properly too.

Comment 2 customercare 2011-11-28 10:09:03 UTC
"I'm struggling to reproduce this. I've tried running "/usr/bin/killall -HUP
proftpd" on a Fedora 15 VM and I get the "reparsing configuration file" message
in the logs but it otherwise carries on as normal."

It was persistent for weeks until i changed the -HUP to the full restart.

I will check that on fc16 too soon. Can you set a reminder for this bug in... lets say 3 weeks ?

In the meantime, maybe this is helpful: 

+++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
/etc/proftpd.conf
+++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++

ServerName                      "ProFTPD server"
ServerIdent                     on "FTP Server ready."
ServerAdmin                     root@localhost
ServerType                      standalone
DefaultServer                   on
AccessGrantMsg                  "User %u logged in."
DeferWelcome                    off
DefaultRoot                     ~ !adm

AuthPAMConfig                   proftpd
AuthOrder                       mod_sql.c mod_auth_pam.c mod_auth_unix.c

AllowOverwrite on
AllowRetrieveRestart on
AllowStoreRestart on

IdentLookups                    off
UseReverseDNS                   off
tcpNoDelay                      off

Port                            21
Umask                           022
ListOptions                     "-a"
AllowRetrieveRestart            on
AllowStoreRestart               on
MaxInstances                    20
User                            nobody
Group                           nobody
UseSendfile                     no
ScoreboardFile                  /var/run/proftpd.score
<Global>
  RootLogin                off
  AllowOverwrite                yes
  AuthPAM                       on
  <Limit ALL SITE_CHMOD>
    AllowAll
  </Limit>
</Global>

LogFormat                       default "%h %l %u %t \"%r\" %s %b"
LogFormat                       auth    "%v [%P] %h %t \"%r\" %s"

#debugLevel 10
Serverlog /var/log/proftpd/proftpd.log

#ExtendedLog /var/log/proftpd/auth_log AUTH auth
TransferLog /var/log/xferlog

<IfModule mod_dso.c>
  LoadModule mod_ban.c
  LoadModule mod_ifsession.c
  LoadModule mod_quotatab.c
  LoadModule mod_quotatab_file.c
  LoadModule mod_sql.c
  LoadModule mod_sql_mysql.c
</IfModule>
<IfModule mod_ban.c>
  BanEngine on
  BanLog /var/log/proftpd/ban.log
  BanTable /var/run/proftpd/ban.tab
  # If the same client reaches the MaxLoginAttempts limit 2 times
  # within 10 minutes, automatically add a ban for that client that
  # will expire after one hour.
  BanOnEvent MaxLoginAttempts 2/00:10:00 01:00:00
  # Allow the FTP admin to manually add/remove bans
  BanControlsACLs all allow user ftpadm
</IfModule>

RequireValidShell on

SQLAuthTypes Crypt
#SQLAuthenticate users usersetfast
SQLAuthenticate users
SQLConnectInfo ************************
SQLDefaultGID 65534
SQLDefaultUID 65534
SQLMinUserGID 100
SQLMinUserUID 500
SQLUserInfo proftpd_users username password uid gid homedir shell
#SQLGroupInfo proftpd_groups groupname gid members
SQLLog PASS counter
SQLNamedQuery counter UPDATE "letzter_zugriff=now(), count=count+1 WHERE username='%u'" proftpd_users
#SQLLOGFILE /var/log/proftpd/sql.log 


+++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
/etc/init.d/proftpd 
+++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
#!/bin/sh
#
# Startup script for ProFTPD
#
# chkconfig: 2345 85 15
# description: ProFTPD is an enhanced FTP server with a focus towards \
#              simplicity, security, and ease of configuration. \
#              It features a very Apache-like configuration syntax, \
#              and a highly customizable server infrastructure, \
#              including support for multiple 'virtual' FTP servers, \
#              anonymous FTP, and permission-based directory visibility.
# processname: proftpd
# config: /etc/proftpd.conf
# pidfile: /var/run/proftpd/proftpd.pid

...
untampered from here
...

+++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
/var/run
+++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++

# ls -la /var/run/ | grep proftp
drwxr-xr-x   2 root    root     120 27. Nov 03:36 proftpd
-rw-r--r--   1 root    root      16 27. Nov 03:36 proftpd.score
-rw-r--r--   1 root    root       0 27. Nov 03:36 proftpd.score.lck

# ls -la /var/run/proftpd
insgesamt 12
drwxr-xr-x  2 root root  120 27. Nov 03:36 .
drwxr-xr-x 26 root root  940 28. Nov 10:01 ..
-rw-r--r--  1 root root    0 15. Nov 19:43 ban.tab
-rw-r--r--  1 root root 6440 27. Nov 03:36 proftpd.delay
-rw-r--r--  1 root root    6 27. Nov 03:36 proftpd.pid
srwxrwxrwx  1 root root    0 27. Nov 03:36 proftpd.sock

Comment 3 Paul Howarth 2011-11-28 13:53:29 UTC
If you do the killall -HUP manually (or /etc/init.d/proftpd reload), does that kill the server?

Comment 4 customercare 2011-11-29 09:41:00 UTC
no, neither does work. Which isn't suprising, as "reload" just executes : "killproc proftpd -HUP" .

# pstree -up | grep proftpd
           |-proftpd(10772,nobody)
# killall -HUP proftpd
# pstree -up | grep proftpd
# /etc/init.d/proftpd start
Starting proftpd (via systemctl):                          [  OK  ]
# pstree -up | grep proftpd
# /etc/init.d/proftpd try-restart
Restarting proftpd (via systemctl):                        [  OK  ]
# pstree -up | grep proftpd
           |-proftpd(12856,nobody)
# /etc/init.d/proftpd reload
Reloading proftpd configuration (via systemctl):           [  OK  ]
# pstree -up | grep proftpd
#  /etc/init.d/proftpd try-restart
Restarting proftpd (via systemctl):                        [  OK  ]
[root@c1 rdt]# pstree -up | grep proftpd
           |-proftpd(12949,nobody)


proftpd.log is emtpy
debug.log is empty
only ban.log shows something:

Nov 29 10:30:30 mod_ban/0.6[12855]: obtained shmid 229376 for BanTable '/var/run/proftpd/ban.tab'
Nov 29 10:31:03 mod_ban/0.6[12948]: obtained shmid 229376 for BanTable '/var/run/proftpd/ban.tab'

Heres the /v/l/messages : 

Nov 29 10:29:54 c1 proftpd[10772]: 83.246.67.243 - received SIGHUP -- master server reparsing configuration file
Nov 29 10:29:54 c1 systemd[1]: PID 10772 read from file /var/run/proftpd/proftpd.pid does not exist. Your service or init script might be broken.
Nov 29 10:29:54 c1 systemd[1]: proftpd.service: main process exited, code=exited, status=127
Nov 29 10:30:30 c1 systemd[1]: Unit proftpd.service entered failed state.
Nov 29 10:30:30 c1 proftpd[12856]: 83.246.67.243 - ProFTPD 1.3.4 (stable) (built Thu Nov 10 2011 20:03:07 UTC) standalone mode STARTUP
Nov 29 10:30:56 c1 proftpd[12856]: 83.246.67.243 - received SIGHUP -- master server reparsing configuration file
Nov 29 10:30:56 c1 systemd[1]: PID 12856 read from file /var/run/proftpd/proftpd.pid does not exist. Your service or init script might be broken.
Nov 29 10:30:56 c1 systemd[1]: proftpd.service: main process exited, code=exited, status=127
Nov 29 10:31:03 c1 systemd[1]: Unit proftpd.service entered failed state.
Nov 29 10:31:03 c1 proftpd[12949]: 83.246.67.243 - ProFTPD 1.3.4 (stable) (built Thu Nov 10 2011 20:03:07 UTC) standalone mode STARTUP

I have watched /v/run/proftpd:

insgesamt 12
drwxr-xr-x  2 root root  120 29. Nov 10:31 .
drwxr-xr-x 26 root root  940 29. Nov 10:31 ..
-rw-r--r--  1 root root    0 15. Nov 19:43 ban.tab
-rw-r--r--  1 root root 6440 27. Nov 03:36 proftpd.delay
-rw-r--r--  1 root root    6 29. Nov 10:31 proftpd.pid
srwxrwxrwx  1 root root    0 29. Nov 10:31 proftpd.sock  

The PID file did not change, nor did it got removed. Systemds default message about the broken initscript may be true ;)

with the option try-restart , i get a new pid file ( as expected )

The proftpd guys should look into it.

Comment 5 Paul Howarth 2011-11-29 09:50:37 UTC
Yes, the HUP shouldn't be killing the server; that's the problem, rather than the initscript. I'll raise it upstream.

Comment 6 Paul Howarth 2011-12-02 14:27:10 UTC
Reported upstream: http://bugs.proftpd.org/show_bug.cgi?id=3724

Comment 7 Paul Howarth 2011-12-02 18:28:02 UTC
Would it be possible to get the SQLLogFile data as well, to see if perhaps
something in mod_sql/mod_sql_mysql doesn't like the restart?

Comment 8 customercare 2011-12-05 11:30:55 UTC
With this option: 

SQLLOGFILE /var/log/proftpd/sql.log

The SQL log is not filled with data on the startup try after a -HUP :

# ls -la /var/log/proftpd/sql.log
-rw-r----- 1 root root 0 23. Okt 03:31 /var/log/proftpd/sql.log

Comment 9 Fedora Update System 2012-02-28 22:20:14 UTC
proftpd-1.3.4a-5.fc15 has been submitted as an update for Fedora 15.
https://admin.fedoraproject.org/updates/proftpd-1.3.4a-5.fc15

Comment 10 Fedora Update System 2012-03-01 09:27:08 UTC
Package proftpd-1.3.4a-5.fc15:
* should fix your issue,
* was pushed to the Fedora 15 testing repository,
* should be available at your local mirror within two days.
Update it with:
# su -c 'yum update --enablerepo=updates-testing proftpd-1.3.4a-5.fc15'
as soon as you are able to.
Please go to the following url:
https://admin.fedoraproject.org/updates/FEDORA-2012-2735/proftpd-1.3.4a-5.fc15
then log in and leave karma (feedback).

Comment 11 Fedora Update System 2012-03-08 21:22:08 UTC
proftpd-1.3.4a-5.fc15 has been pushed to the Fedora 15 stable repository.  If problems still persist, please make note of it in this bug report.


Note You need to log in before you can comment on or make changes to this bug.