Cron/MailGate issue

dralusd · 2010-01-14 21:32:45

I've been running GLPI for about a year now, but recently moved to a more robust server running Ubuntu 8.04, PHP 5.2.4. I have GLPI 0.72.3. The mail gateway running through cron worked great on the old server (which also ran on Ubuntu 8.04, but was the previous version of GLPI), but I've hit some sort of glitch on the new.

I have 1 mail gateway configured under Receivers. It is an IMAP over SSL connection to our Exchange 07 server. If I manually click the "Get email tickets now" button, the connection is fine and I'll get the tickets.

If I'm active in the web interface, the tickets are retrieved just fine.

I've created a crontab entry for my apache user (www-data):
*/5 * * * * /usr/bin/php5 /var/www/glpi/front/cron.php &>/dev/null

I've turned on debugging in GLPI and the cron log is being generated. Everything else (like the OCSNG synchronization) seems to be running just fine. The cron.log file shows regular entries indicating the mail gateway process has been launched like so:
-----
Launch mailgate
2010-01-14 12:10
Collect mails from {mail.franklinroadacademy.com:993/imap/ssl/novalidate-cert/notls} for Root entity
-----
These entries appear regularly, but I can verify that mail sent to the mailbox in question often sits there through many of the cron cycles before it is actually retrieved (and again, that only happens while we are active in the web interface). Overnight, for example, I can send a test email and although the cron.log file shows the "Launch mailgate" entries running throughout the night, the message is not retrieved until someone logs into the web interface the next morning, at which point the message is promptly retrieved and processed.

Checking the log files on the mail server shows no IMAP connections from the glpi user account overnight (i.e. no failed login attempts).

I've also noticed in the cron.log file that some of the mailgate entries are followed with a line like:
Number of messages available and collected : 1

Most of the "Launch mailgate" entries are *not* followed by a report of the number of messages available (which seems to fit with the idea that it is not actually connecting to the mail server). For example, for Jan. 13th (00:02-23:58) there are 358 entries for "Launch mailgate" but only 14 for "Number of messages available". The first entry for "Number of messages" is at 7:06 a.m. (when I got to the office and logged in) and the latest one was at 14:06. The next day, the first entry for "Number of message" was at 6:56 (again, when I logged in that morning).

I've found one forum entry that seems similar, but the fix was to upgrade to the current GLPI version, which I'm already running. I've re-downloaded the current package and run a diff on the cron.php, mailgate.class.php and mailgate.function.php and there are no differences.

I'm stumped. Any suggestions on what to check next, or how to enable more error reporting would be appreciated.

JMD · 2010-01-15 00:47:14

Humm, hard to debug

Do you have any info when you put GLPI in debug mode and active Logs in files

dralusd · 2010-01-15 15:48:09

I've set the log level to 5. I'm seeing 4 log files generated in glpi/files/_log:
cron.log
mail.log
php-errors.log
sql-errors.log

The php-errors.log and sql-errors.log are blank. The mail.log has entries about outbound messages (no problems with the SMTP connector at all).

The cron.log file has entries as noted above. As an example:
----------------------------
Launch mailgate
2010-01-14 11:20
Collect mails from {mail.franklinroadacademy.com:993/imap/ssl/novalidate-cert/notls} for Root entity
2010-01-14 11:24
Launch ocsng
2010-01-14 11:24
Check updates from server localhost
2010-01-14 11:24
Update computer 17615
2010-01-14 11:24
ocsng task was done (0.20s)
2010-01-14 11:25
Launch dbreplicate
2010-01-14 11:25
dbreplicate Nothing to do (0.00s)
2010-01-14 11:30
Launch mailgate
2010-01-14 11:30
Collect mails from {mail.franklinroadacademy.com:993/imap/ssl/novalidate-cert/notls} for Root entity
----------------------------------
This is typical. I see no time gaps in the timing of the Launch mailgate entries, but the smtp server does not show corresponding connection attempts in its log.

Is there a way to turn on more detailed debugging to see what happens after the "Launch mailgate" entry is generated in the log?

Last edited by dralusd (2010-01-15 17:14:04)

dralusd · 2010-01-15 17:13:40

Here's a better example of the cron.log output from today.

I sent a test message to our GLPI mail account at 8:38 this morning. Here is the cron.log output that follows:

2010-01-15 08:40
Launch mailgate
2010-01-15 08:40
Collect mails from {65.105.183.220:993/imap/ssl/novalidate-cert/notls} for Root entity
2010-01-15 08:45
Launch ocsng
2010-01-15 08:45
Check updates from server localhost
2010-01-15 08:45
Update computer 17690
2010-01-15 08:45
Update computer 17691
2010-01-15 08:45
Update computer 17259
2010-01-15 08:45
ocsng task was done (0.82s)
2010-01-15 08:47
Launch dbreplicate
2010-01-15 08:47
dbreplicate Nothing to do (0.00s)
2010-01-15 08:50
Launch mailgate
2010-01-15 08:50
Collect mails from {65.105.183.220:993/imap/ssl/novalidate-cert/notls} for Root entity
2010-01-15 08:55
Launch ocsng
2010-01-15 08:55
Check updates from server localhost
2010-01-15 08:55
Update computer 17692
2010-01-15 08:55
Update computer 17489
2010-01-15 08:55
ocsng task was done (0.29s)
2010-01-15 09:00
Launch dbreplicate
2010-01-15 09:00
dbreplicate Nothing to do (0.00s)
2010-01-15 09:02
Launch mailgate
2010-01-15 09:02
Collect mails from {65.105.183.220:993/imap/ssl/novalidate-cert/notls} for Root entity
2010-01-15 09:02
Number of messages available and collected : 1
2010-01-15 09:02
mailgate task was done (0.31s)

So the 8:40 mailgate process was launched, but there is no entry indicating that it finished or connected with the mail server.

It launched again at 8:50 and again there is no subsequent entry indicating that it finished.

It launched again at 9:00 and at 9:02 reported that found and collected my test message.

JMD · 2010-01-15 20:43:18

Stupide question but the message was already in the mail box à 8h40 ?

dralusd · 2010-01-15 20:47:08

Yes.

And I've repeated the test today. As I write this, I have a message sitting in the GLPI mailbox (timestamp is 12:14), and I'm monitoring the cron.log file. I see entries for "Collect mails" at 12:20, 12:30 and 12:40 (local time is now 12:46) but so far the message is still sitting in the mailbox and the GLPI cron process has not retrieved it.

dj_Duff · 2010-10-27 08:04:59

the SAME problem!
I ve done everything like dralusd, but mailgate doesn't automate the process.

What is the solution?
Can someone help me?

Last edited by dj_Duff (2010-10-27 08:05:09)

breyko · 2012-07-26 15:40:53

encontraron la solucion?, me ocurre lo mismo.
found the solution?, I do, too.

Last edited by breyko (2012-07-26 15:41:20)

Forum GLPI-Project

Announcement

#1 2010-01-14 21:32:45

Cron/MailGate issue

#2 2010-01-15 00:47:14

Re: Cron/MailGate issue

#3 2010-01-15 15:48:09

Re: Cron/MailGate issue

#4 2010-01-15 17:13:40

Re: Cron/MailGate issue

#5 2010-01-15 20:43:18

Re: Cron/MailGate issue

#6 2010-01-15 20:47:08

Re: Cron/MailGate issue

#7 2010-10-27 08:04:59

Re: Cron/MailGate issue

#8 2012-07-26 15:40:53

Re: Cron/MailGate issue

Board footer