Bug 55985

Since we want to use different "postrotate" scripts for different CustomLogs, we configure lgrotate with 3 different sections, one for each "type" of log file. Since none of the sections is guaranteed to run every time, each has its own call to apachectl graceful. Sometimes, this causes multiple calls to apachectl graceful within the same second, which in turn sometimes results in httpd not reopening the access logs. This is usually fixed by manually performing an apachectl graceful at a later time, but httpd may just as well continue to write to the same (deleted) access_log.1 for multiple days. This results in log data that never gets analyzed or can result in the /var partition filling up.

I was able to reproduce this behaviour by running ab, a loop that just does graceful restarts every 5 seconds, and a second loop that uses lsof to find deleted files opened by httpd processes and forces logrotate to run for the single configured transfer log. I only have a single virtualhost configured, and ab is requesting a small static file.

bin/ab -n 999999 -c 4 -t 10000 http://testserver:10106/favicon.ico

for i in {1..1000}; do 
   echo $i; 
   lsof |grep httpd |grep deleted | egrep -v 'ssl_mutex'; 
   echo; 
   logrotate  -f logrotate.conf ; 
   j=0; 
   while lsof |grep httpd |grep deleted | egrep -v 'ssl_mutex'; do 
      echo ====== $j ======; sleep 1; j=$[ $j + 1 ]; 
   done; 
done

while true; do apachectl graceful; sleep 5; done

I've tried httpd 2.2.22, 2.2.24 and 2.2.26 on debian Wheezy (i686), RHEL 6.5 x86_64 and SLES 11 SP2 x86_64, all of which show the described behavior. The deleted access_log.1 is used even by children forked after the previous ones have exceeded their MaxRequestsPerChild.
 
httpd  -t -D DUMP_MODULES
Loaded Modules:
 core_module (static)
 authn_file_module (static)
 authn_default_module (static)
 authz_host_module (static)
 authz_groupfile_module (static)
 authz_user_module (static)
 authz_default_module (static)
 auth_basic_module (static)
 cache_module (static)
 disk_cache_module (static)
 mem_cache_module (static)
 include_module (static)
 filter_module (static)
 deflate_module (static)
 log_config_module (static)
 log_forensic_module (static)
 logio_module (static)
 env_module (static)
 expires_module (static)
 headers_module (static)
 unique_id_module (static)
 setenvif_module (static)
 version_module (static)
 proxy_module (static)
 proxy_connect_module (static)
 proxy_ftp_module (static)
 proxy_http_module (static)
 proxy_scgi_module (static)
 proxy_ajp_module (static)
 proxy_balancer_module (static)
 ssl_module (static)
 mpm_prefork_module (static)
 http_module (static)
 mime_module (static)
 dav_module (static)
 status_module (static)
 autoindex_module (static)
 asis_module (static)
 cgi_module (static)
 dav_fs_module (static)
 dav_lock_module (static)
 vhost_alias_module (static)
 negotiation_module (static)
 dir_module (static)
 actions_module (static)
 userdir_module (static)
 alias_module (static)
 rewrite_module (static)
 so_module (static)
Syntax OK

the logrotate.conf used:

logs/access_log {
        su rainer rainer
	compress
	nodelaycompress
	compresscmd /bin/bzip2
	compressext .bz2
	create 644 rainer rainer
	sharedscripts
	postrotate
		bin/apachectl graceful
	endscript
}