Paul Douglas Franklin | 1 Jul 2008 19:42
Favicon

Re: Fw: Zero emails again

Gunnar Wrobel wrote:
> Paul Franklin <yugm6161 <at> yahoo.com> writes:
>
>   
>> Alain,                                                                                                                                                                           
>> Thanks again for your tutorial.  I have now had opportunity to put it into practice.  I did not get very far in
the process, however, before I discovered a sign of what is      
>> wrong.  I just don't know what to do with the sign.                                                                                                                              
>>                                                                                                                                                                                  
>> This morning mail delivery stopped at around 10:30.  The postfix log shows messages such as                                                                                      
>>                                                                                                                                                                                  
>> Jun 30 20:23:26 exchange <info> postfix/pipe[20064]: 52F63384220: to=<yugm6161 <at> yahoo.com>,
relay=kolabfilter, delay=0, status=sent (exchange.yugm.org)                           
>> Jun 30 20:23:26 exchange <info> postfix/qmgr[3142]: 5B0DC384230: to=<yugm6161 <at> yahoo.com>,
relay=none, delay=0, status=deferred (delivery temporarily suspended: connect to       
>> 127.0.0.1[127.0.0.1]: Connection refused)                                                                                                                                        
>>                                                                                                                                                                                  
>> I grepped for "temporarily" and discovered that when the mail first stopped, a typical log entry was                                                                             
>>                                                                                                                                                                                  
>> Jun 30 10:31:22 exchange <info> postfix/qmgr[3142]: 64EBF457B7C: to=<archive <at> yugm.org>,
relay=none, delay=703, status=deferred (delivery temporarily suspended: connect to       
>> 127.0.0.1[127.0.0.1]: read timeout)                                                                                                                                              
>>                                                                                                                                                                                  
>> I'm going to reboot my kolab box since that is what seemed to do the
>> job last time.  I would like, however, to figure out what is causing
>> this occasional problem.  Given this information, where would you
>> look next?
>>     
>
> Looks like your amavisd-new process is failing here. You should be
> able to restart it with
>
> /kolab/bin/openpkg rc amavisd
>
> On the other hand it should not be failing in the first place. Do you
> see anything in the amavisd logs?
>
>   
I see some things.
At 10:10:07 I issued the /kolab/bin/openpkg rc all restart command.  It 
went thru quite a process, finishing at 10:10:44.  (More about that 
later.)  Then, at 10:11:52, I issued the /kolab/bin/openpkg rc amavisd 
restart command (just to get it moved into my recent history--I knew 
amavisd was included in all).  It was at this point that problems 
happened, but without any indication of why.  There are exactly two 
lines in the log here:

Jun 30 10:11:52 exchange.yugm.org /kolab/sbin/amavisd[4330]: starting.  /kolab/sbin/amavisd at
exchange.yugm.org amavisd-new-2.3.3 (20050822), Unicode aware, LANG=en_US.UTF-8
Jun 30 10:11:52 exchange.yugm.org /kolab/sbin/amavisd[4330]: Perl version               5.008007

The next entry wasn't until I rebooted at 20:52.  So it does appear that 
amavisd didn't load, but it doesn't say why.

There is another thing that I see that causes me concern.  Toward the 
end of the restart, it appears that clam fails.

Jun 30 20:52:07 exchange.yugm.org /kolab/sbin/amavisd[5274]: No decoder for       .rar  tried: rar, unrar
Jun 30 20:52:07 exchange.yugm.org /kolab/sbin/amavisd[5274]: No decoder for       .arj  tried: arj, unarj
Jun 30 20:52:07 exchange.yugm.org /kolab/sbin/amavisd[5274]: No decoder for       .arc  tried: nomarch, arc
Jun 30 20:52:07 exchange.yugm.org /kolab/sbin/amavisd[5274]: No decoder for       .zoo  tried: zoo
Jun 30 20:52:07 exchange.yugm.org /kolab/sbin/amavisd[5274]: No decoder for       .lha  tried: lha
Jun 30 20:52:07 exchange.yugm.org /kolab/sbin/amavisd[5274]: No decoder for       .doc 
Jun 30 20:52:07 exchange.yugm.org /kolab/sbin/amavisd[5274]: No decoder for       .cab 
Jun 30 20:52:07 exchange.yugm.org /kolab/sbin/amavisd[5274]: No decoder for       .tnef
Jun 30 20:52:07 exchange.yugm.org /kolab/sbin/amavisd[5274]: Internal decoder for .tnef
Jun 30 20:52:07 exchange.yugm.org /kolab/sbin/amavisd[5274]: No decoder for       .exe  tried: rar, unrar;
lha; arj, unarj
Jun 30 20:52:07 exchange.yugm.org /kolab/sbin/amavisd[5274]: Using internal av scanner code for
(primary) Clam Antivirus-clamd
Jun 30 20:52:07 exchange.yugm.org /kolab/sbin/amavisd[5274]: Found secondary av scanner Clam
Antivirus - /kolab/bin/clamscan at /kolab/bin/clamscan
Jun 30 20:52:16 exchange.yugm.org /kolab/sbin/amavisd[5359]: (05359-01) Clam Antivirus-clamd:
Can't connect to UNIX socket /kolab/var/clamav/clamd.sock: No such file or directory, retrying (2)
Jun 30 20:52:16 exchange.yugm.org /kolab/sbin/amavisd[5360]: (05360-01) Clam Antivirus-clamd:
Can't connect to UNIX socket /kolab/var/clamav/clamd.sock: No such file or directory, retrying (2)
Jun 30 20:52:22 exchange.yugm.org /kolab/sbin/amavisd[5359]: (05359-01) Clam Antivirus-clamd
av-scanner FAILED: Too many retries to talk to /kolab/var/clamav/clamd.sock (Can't connect to UNIX
socket /kolab/var/clamav/clamd.sock: No such file or directory) at (eval 55) line 266.
Jun 30 20:52:22 exchange.yugm.org /kolab/sbin/amavisd[5359]: (05359-01) WARN: all primary virus
scanners failed, considering backups
Jun 30 20:52:22 exchange.yugm.org /kolab/sbin/amavisd[5360]: (05360-01) Clam Antivirus-clamd
av-scanner FAILED: Too many retries to talk to /kolab/var/clamav/clamd.sock (Can't connect to UNIX
socket /kolab/var/clamav/clamd.sock: No such file or directory) at (eval 55) line 266.
Jun 30 20:52:22 exchange.yugm.org /kolab/sbin/amavisd[5360]: (05360-01) WARN: all primary virus
scanners failed, considering backups

Looking at the clamav log, I see that it started at 20:52:09.
Is this indeed saying that I have no antivirus protection?
--Paul

> Cheers,
>
> Gunnar
>   
>
--

-- 
Paul Douglas Franklin
Computer Manager, Union Gospel Mission of Yakima, Washington
Husband of Danette
Father of Laurene, Miriam, Tycko, Timothy, Sarabeth, Marie, Dawnita, Anna Leah, Alexander, and Caleb

Gmane