mail_logs.php cron job causing high server loads?

Discussion in 'General' started by jameso, Mar 28, 2007.

  1. jameso

    jameso New Member

    Hi everyone,

    Following on from my previous thread, I have discovered that one of ISPconfig's cron jobs is causing my server load to go in excess of 3 or 4 after midnight when the job begins to run.

    I'm running Ubuntu Linux 6.06 with ISPconfig 2.10.

    Top demonstrates that php is constantly using approximately 35% CPU. The server load stays high until I reboot the server.

    The offending cron job is:
    Code:
    59 23 * * * /root/ispconfig/php/php /root/ispconfig/scripts/shell/mail_logs.php &> /dev/null
    This is scheduled to run at 11:59pm every night.

    When I run this command manually, I get output such as the following:
    Code:
    Warning: feof(): supplied argument is not a valid stream resource in /root/ispcoonfig/scripts/shell/mail_logs.php on line 114
    
    Warning: fgets(): supplied argument is not a valid stream resource in /root/ispconfig/scripts/shell/mail_logs.php on line 115
    
    Warning: feof(): supplied argument is not a valid stream resource in /root/ispcoonfig/scripts/shell/mail_logs.php on line 114
    
    Warning: fgets(): supplied argument is not a valid stream resource in /root/ispconfig/scripts/shell/mail_logs.php on line 115
    .
    .
    .
    etc
    As far as I can tell, this cron job never seems to finish executing, which is what is causing the high server loads.

    This part of the php script is referring to files inside /home/admispconfig/mailstats/. Somehow this seems to be causing the error.

    At present this folder only contains one file, which has a whole series of numbers, each on a new line.

    Has anyone else experienced this problem?

    What do you get when you run:
    Code:
    /root/ispconfig/php/php /root/ispconfig/scripts/shell/mail_logs.php
    Does the script complete, or does it spit out errors such as the ones I am receiving?

    Or even better, has anyone come up with a solution to the problem?

    Thanks in advance.
     
    Last edited: Mar 28, 2007
  2. till

    till Super Moderator Staff Member ISPConfig Developer

    Please make sure that the path to your mail logfile is set correctly in ISPConfig under management > server > settings on the mail tab.

    There are no known problems with this script.
     
  3. jameso

    jameso New Member

    Hi Till,

    Thanks for your reply.

    The mail log in ISPconfig's settings is set as /var/log/mail.log.

    This file exists, and is approximtely 980K in size.

    Any other ideas what could be causing the problem?

    Thanks!
     
  4. falko

    falko Super Moderator Howtoforge Staff

    Please post the output of
    Code:
    ls -la /home/admispconfig/mailstats/
     
  5. jameso

    jameso New Member

    Code:
    #ls -la /home/admispconfig/mailstats/
    
    total 16
    drwxr-xr-x 2 admispconfig admispconfig 4096 Mar 27 18:43 .
    drwxr-xr-x 4 admispconfig admispconfig 4096 Nov 17 16:52 ..
    -rwxr-xr-x 1 admispconfig admispconfig 1114 Feb 12 22:32 web1_james
    -rw------- 1 admispconfig admispconfig 2171 Mar 29 17:28 web5_james
    Looking at that, maybe it's something to do with the permissions on the web5_james file? They seem to be different to the web1_james file?

    The cron job would run as root though, wouldn't it?

    Thanks.
     
  6. falko

    falko Super Moderator Howtoforge Staff

    Try to change the permissons of web5_james to 755, and then run
    Code:
    /root/ispconfig/php/php /root/ispconfig/scripts/shell/mail_logs.php
    Does that change anything?
     
  7. jameso

    jameso New Member

    Hi Falko,

    Thanks for your reply once again.

    No it doesn't seem to make a difference.

    I just noticed that the beginning of the mail_logs.php output said something about grep and some kind of error. The message disappeared too quickly to see it though.

    Shortly after this message showed a few times, the PHP feof and fgets errors started to appear.

    So it seems that the errors are being caused by a grep command higher up in the script failing for some reason.

    When I try and rerun the mail_logs.php script, I get:
    Code:
    root@srv02:/home/admispconfig/mailstats# /root/ispconfig/php/php /root/ispconfig/scripts/shell/mail_logs.php
    Usage: grep [OPTION]... PATTERN [FILE]...
    Try `grep --help' for more information.
    sh: -c: line 1: syntax error near unexpected token `|'
    sh: -c: line 1: ` | grep -iw Mar | cut -f2 -d, | cut -f2 -d= >> /var/log/mail.log.www.domain.com'
    
     
  8. jameso

    jameso New Member

    Ok, I reran the script and managed to catch some of the initial output:
    Code:
    root@srv02:/home/admispconfig/mailstats# /root/ispconfig/php/php /root/ispconfig/scripts/shell/mail_logs.php
    Usage: grep [OPTION]... PATTERN [FILE]...
    Try `grep --help' for more information.
    
    Warning: fopen(/home/admispconfig/mailstats/web5_james): failed to open stream: No such file or directory in /root/ispconfig/scripts/shell/mail_logs.php on line 113
    
    Warning: feof(): supplied argument is not a valid stream resource in /root/ispconfig/scripts/shell/mail_logs.php on line 114
    
    Warning: fgets(): supplied argument is not a valid stream resource in /root/ispconfig/scripts/shell/mail_logs.php on line 115
    
    Warning: feof(): supplied argument is not a valid stream resource in /root/ispconfig/scripts/shell/mail_logs.php on line 114
    
    Warning: fgets(): supplied argument is not a valid stream resource in /root/ispconfig/scripts/shell/mail_logs.php on line 115
    
    Warning: feof(): supplied argument is not a valid stream resource in /root/ispconfig/scripts/shell/mail_logs.php on line 114
    
    Warning: fgets(): supplied argument is not a valid stream resource in /root/ispconfig/scripts/shell/mail_logs.php on line 115
     
  9. falko

    falko Super Moderator Howtoforge Staff

    What's the value of the server_mta field in the isp_server table of your ISPConfig database?
     
  10. jameso

    jameso New Member

    postfix

    I initially installed ubuntu using the perfect setup for 6.06, which includes postfix.
     
  11. falko

    falko Super Moderator Howtoforge Staff

    And what's in the dist_mail_log field?
     
  12. jameso

    jameso New Member

    /var/log/mail.log, which is the correct mail log file. The file exists, and has entries in it from 1 minute ago.

    This situation is very strange indeed.

    I haven't had to reboot the server since I disabled the cron job (5+ days now).

    What does the mail_logs cron job do? I assume it processes the logs file and gathers stats for each domain or something?

    Can you think of anything else that may be causing the problem?
     
  13. falko

    falko Super Moderator Howtoforge Staff

    That's right.

    I think all you can do is put some echo statements into the /root/ispconfig/scripts/shell/mail_logs.php script to see what values the variables hold at what stage:

    PHP:
    echo $variablename;
     
  14. jameso

    jameso New Member

    Ok, I have slightly modified the mail_logs.php cron job as follows. There don't seem to be any errors any more. May I suggest updating this file for the next ISPconfig release?

    Before:
    Code:
    $fd = fopen("$dist_mail_log.$vhost", "r");
    
    while(!feof($fd)){
    	$buffer = trim(fgets($fd, 4096));
    	 if(is_numeric($buffer)) $traffic += $buffer;
    }
    fclose ($fd);
    
    After:
    Code:
    $fd = @fopen("$dist_mail_log.$vhost", "r");
    if ($fd) {
    	while(!feof($fd)){
    		$buffer = trim(fgets($fd, 4096));
    	  	if(is_numeric($buffer)) $traffic += $buffer;
    	}
    	fclose ($fd);
    }
    
    Before:
    Code:
    if(is_file("/home/admispconfig/mailstats/".$user["user_username"])){
          $fd = fopen("/home/admispconfig/mailstats/".$user["user_username"], "r");
          	while(!feof($fd)){
            $buffer = trim(fgets($fd, 4096));
            if(is_numeric($buffer)) $traffic += $buffer;
          	}
          	fclose ($fd);
          	$mod->log->caselog("rm -f /home/admispconfig/mailstats/".$user["user_username"], $FILE, __LINE__);
    }
    
    After:
    Code:
    if(is_file("/home/admispconfig/mailstats/".$user["user_username"])){
          $fd = @fopen("/home/admispconfig/mailstats/".$user["user_username"], "r");
    	if ($fd) {
          		while(!feof($fd)){
            	$buffer = trim(fgets($fd, 4096));
            	if(is_numeric($buffer)) $traffic += $buffer;
          		}
          		fclose ($fd);
          		$mod->log->caselog("rm -f /home/admispconfig/mailstats/".$user["user_username"], $FILE, __LINE__);
    	}
        }
    
    Basically, the code now checks that the file was opened properly before proceeding.
     
  15. jameso

    jameso New Member

    Also, I thought I'd post a graph of my server's load since disabling the mail_logs.php script.

    It's pretty easy to tell when I disabled it don't you think?!?!

    Since modifying the script as per the post above, I have re enabled the cron job.

    The 11:59 cron job just ran, and the server load has stayed low and the job seems to have completed without error.

    Thanks everyone for their help!!
     

    Attached Files:

  16. till

    till Super Moderator Staff Member ISPConfig Developer

    Thanks for the patch. I will add it to the ISPConfig sources.
     

Share This Page