Submitted by Shirehosting on Sat, 03/03/2012 - 08:52 Pro Licensee
Hi Guys,
I'm not sure what has happened to our Virtualmin server but for some time now It has not run I would say a single cron, but just as i'm thinking about it I think it does run some crons as I suspect that the Virtualmin updates are found only after a cron is run. would that be correct. anyway the issue that we have is that our WHMCS cron jobs are not being executed.
Any Ideas
Peter
Status:
Active
Comments
Submitted by andreychek on Sat, 03/03/2012 - 08:59 Comment #1
Howdy -- you can see what cron jobs are running by looking in /var/log/syslog, and searching for the text "CRON".
Do you see it running any cron jobs in there?
Submitted by JamieCameron on Sat, 03/03/2012 - 10:20 Comment #2
Also, check if the crond process is running on your system - without it, cron jobs won't be executed.
Submitted by Shirehosting on Sat, 03/03/2012 - 18:31 Pro Licensee Comment #3
hi guys,
ok I looked at the process PID'S and found a process called "cron" not "crond" that is running. Its Parent process is /sbin/init
I also looked at the services in the "Bootup and shudown" menu and the "cron" service is there and set to start at bootup.
So I'm uncirtain where i should look next...
Cheers
Peter
Submitted by Shirehosting on Sat, 03/03/2012 - 19:03 Pro Licensee Comment #4
Ok also after looking into the /var/log/syslog
I found the following which are occuring at 1am
Mar 4 01:00:01 c3po CRON[8505]: (root) CMD (/etc/webmin/quota/email.pl) Mar 4 01:00:01 c3po CRON[8502]: (root) CMD (/etc/webmin/status/monitor.pl) Mar 4 01:00:01 c3po CRON[8506]: (root) CMD (/etc/webmin/virtual-server/bw.pl) Mar 4 01:00:01 c3po CRON[8503]: (shirehosting) CMD (/usr/bin/wget -q -O /dev/null http://shirehosting.com.au/members/admin/cron.php) Mar 4 01:00:01 c3po CRON[8510]: (www-data) CMD ([ -x /usr/lib/cgi-bin/awstats.pl -a -f /etc/awstats/awstats.conf -a -r /var/log/apache2/access.log ] && /usr/lib/cgi-bin/awstats.pl -config=awstats -update >/dev/null) Mar 4 01:00:01 c3po CRON[8512]: (CRON) error (popen: setuid(1118) failed: Resource temporarily unavailable)
The important one above is the (shirehosting) job which is supposed to issue overdue invoices remove and suspend servers etc. and it dose not seem to be running.
If however I execute is manually by going into Webmin -> System -> Scheduled Cron Jobs it works fine
Cheers
Peter
Submitted by andreychek on Sat, 03/03/2012 - 19:14 Comment #5
According to your log output there, it does appear that the cron job is being successfully called.
The next step would be to look in the corresponding access and error logs in $HOME/logs, and to see if there's any errors occurring then, or if it's running correctly.
Submitted by Shirehosting on Sat, 03/03/2012 - 21:47 Pro Licensee Comment #6
Ok the Apache error log for the time frame we are looking at reports the following
[Sat Mar 03 00:09:52 2012] [error] [client 150.70.75.32] File does not exist: /home/shirehosting/public_html/plug [Sat Mar 03 00:30:22 2012] [error] [client 208.80.194.33] request failed: error reading the headers [Sat Mar 03 01:50:25 2012] [error] [client 67.205.103.104] File does not exist: /home/shirehosting/public_html/appConf.htm
but none of the above is an error generated at 1am, so still no answer
:-(
Peter
Submitted by Shirehosting on Sat, 03/03/2012 - 21:49 Pro Licensee Comment #7
Guys,
Just keep in mind that if I run the job manually it works fine.
Peter
Submitted by andreychek on Sat, 03/03/2012 - 21:51 Comment #8
What about your access log, is it showing a connection from your own IP address to members/admin/cron.php at 1am?
If so, can you paste in the log entry?
Submitted by Shirehosting on Sat, 03/03/2012 - 22:05 Pro Licensee Comment #9
Ok here it is but doesn't look like there's anything to see of any substance
68.169.41.148 - - [04/Mar/2012:00:30:02 +1100] "HEAD / HTTP/1.0" 200 388 "-" "Webmin" 68.169.41.148 - - [04/Mar/2012:00:35:02 +1100] "HEAD / HTTP/1.0" 200 388 "-" "Webmin" 68.169.41.148 - - [04/Mar/2012:00:40:03 +1100] "HEAD / HTTP/1.0" 200 388 "-" "Webmin" 68.169.41.148 - - [04/Mar/2012:00:45:02 +1100] "HEAD / HTTP/1.0" 200 388 "-" "Webmin" 68.169.41.148 - - [04/Mar/2012:00:50:02 +1100] "HEAD / HTTP/1.0" 200 388 "-" "Webmin" 175.143.151.49 - - [04/Mar/2012:00:51:05 +1100] "-" 408 0 "-" "-" 122.161.27.28 - - [04/Mar/2012:00:51:08 +1100] "-" 408 0 "-" "-" 68.169.41.148 - - [04/Mar/2012:00:55:02 +1100] "HEAD / HTTP/1.0" 200 388 "-" "Webmin" 66.41.218.164 - - [04/Mar/2012:01:46:39 +1100] "-" 408 0 "-" "-" 66.41.218.164 - - [04/Mar/2012:01:46:40 +1100] "-" 408 0 "-" "-" 66.41.218.164 - - [04/Mar/2012:01:46:40 +1100] "-" 408 0 "-" "-" 195.46.165.144 - - [04/Mar/2012:01:47:49 +1100] "-" 408 0 "-" "-" 195.46.165.144 - - [04/Mar/2012:01:47:49 +1100] "-" 408 0 "-" "-"
Our Ip is the 68.168 one
Cheers
Peter
Submitted by andreychek on Sat, 03/03/2012 - 22:14 Comment #10
Just keep in mind that if I run the job manually it works fine.
I believe you -- the issue is just that cron shows that job as running, so we need to figure out what it's actually doing.
Do you get any output if you log into your server as the user "shirehosting", and run this command:
/usr/bin/wget -q -O /dev/null http://shirehosting.com.au/members/admin/cron.phpSubmitted by Shirehosting on Sat, 03/03/2012 - 22:32 Pro Licensee Comment #11
The strangest thing just happened, about 2 comments back I disabled the cron and then re-enabled it and it just ran about 20mins ago at 15:07 Sydney time, even though its set to run at 1am
Submitted by andreychek on Sat, 03/03/2012 - 22:37 Comment #12
Make sure when you see it in your access_log, that it appears to be from your own IP address.
Drupal turned your log entry into a link, and I may have accidentally clicked it, which could have caused the cron job to run :-/
Just to be sure, you may also want to check your systems time by running the command "date", just to verify that your time is correct.
Submitted by Shirehosting on Sat, 03/03/2012 - 22:44 Pro Licensee Comment #13
So the "date" comand returned the following
Which is exactly the time on my desktop.
and I'm just checking the logs now
Submitted by Shirehosting on Sat, 03/03/2012 - 22:48 Pro Licensee Comment #14
ok it may have been you,
does this ip ring a bell 98.117.244.51??
Peter
Submitted by andreychek on Sat, 03/03/2012 - 22:52 Comment #15
Yup, that's me... I was just trying to highlight part of your post as I was reading it, and I managed to accidentally click the link.
When you get a chance though, try what I mentioned in comment #10 above, and see what happens when you do that.
Submitted by Shirehosting on Sat, 03/03/2012 - 23:10 Pro Licensee Comment #16
i gotta tell ya, this has got me f****d, i just set the cron to run at 15:47 and it did.
explain that to me...
Submitted by Shirehosting on Sat, 03/03/2012 - 23:37 Pro Licensee Comment #17
and here is the /var/log/syslog for that time
Mar 4 15:47:01 c3po CRON[16317]: (root) CMD (/etc/webmin/virtual-server/collectinfo.pl) Mar 4 15:47:01 c3po CRON[16318]: (shirehosting) CMD (/usr/bin/wget -q -O /dev/null http://shirehosting.com.au/members/admin/cron.php) Mar 4 15:47:11 c3po postfix/smtpd[16759]: connect from localhost[127.0.0.1]
Submitted by andreychek on Sun, 03/04/2012 - 12:03 Comment #18
Yeah, the cron job running at 15:47 looks the same at the one running at 01:00.
It does appear to be running at 01:00 -- so if it's not working, the next step is to try and determine what, if any, errors are occurring.
There don't seem to be any related errors in the Apache log. But if there's a cron error, it should send that to the Virtual Server owner via email. Is that Virtual Server owner getting any emails regarding that cron job?