alert: cannot start: qmail-send is already running

Hi,

I've inherited a mail server at my work that is sending mail very
slowly. It takes 2-3 minutes to send a message, and when I check the
log, it is a 2mb file that has a number and then "alert: cannot start:
qmail-send is already running" for the whole log.

We have about 50 mailboxes on this server, but only about a dozen are
accessed on a "regular" basis.

The server is running Redhat 6.1, and qmail. I have very limited
experience with Linux and Qmail, so if someone could give me a hand
with getting this problem resolved, it would be greatly appreciated.

Thanks for the help!

Curtis

cferchoff@accesscomm.ca (Curtis) writes:

> I've inherited a mail server at my work that is sending mail very
> slowly. It takes 2-3 minutes to send a message, and when I check the
> log, it is a 2mb file that has a number and then "alert: cannot start:
> qmail-send is already running" for the whole log.
>
> We have about 50 mailboxes on this server, but only about a dozen are
> accessed on a "regular" basis.
>
> The server is running Redhat 6.1, and qmail. I have very limited
> experience with Linux and Qmail, so if someone could give me a hand
> with getting this problem resolved, it would be greatly appreciated.

What does "ps -ef|grep qmail" say?

--
Dave Sill Oak Ridge National Lab, Workstation Support
Author, The qmail Handbook <http://web.infoave.net/~dsill>
<http://lifewithqmail.org/>: Almost everything you always wanted to know.

Dave Sill <MaxFreedom@sws5.ctd.ornl.gov> wrote in message news:<wx0he5n3ff8.fsf@sws5.ornl.gov>...
> cferchoff@accesscomm.ca (Curtis) writes:
>
> > I've inherited a mail server at my work that is sending mail very
> > slowly. It takes 2-3 minutes to send a message, and when I check the
> > log, it is a 2mb file that has a number and then "alert: cannot start:
> > qmail-send is already running" for the whole log.
> >
> > We have about 50 mailboxes on this server, but only about a dozen are
> > accessed on a "regular" basis.
> >
> > The server is running Redhat 6.1, and qmail. I have very limited
> > experience with Linux and Qmail, so if someone could give me a hand
> > with getting this problem resolved, it would be greatly appreciated.
>
> What does "ps -ef|grep qmail" say?

This is what I get:

> ps -ef|grep qmail
root 11724 11721 0 00:00 ? 00:00:00 supervise qmail-send
root 11726 11721 0 00:00 ? 00:00:00 supervise qmail-smtpd
qmails 11728 11724 0 00:00 ? 00:00:02 qmail-send
qmaill 11729 11725 0 00:00 ? 00:00:00 /usr/local/bin/multilog t s25000
qmaill 11730 11727 0 00:00 ? 00:00:00 /usr/local/bin/multilog t s25000
qmaild 11731 11726 0 00:00 ? 00:00:00 /usr/local/bin/tcpserver -P -v -
root 11734 11728 0 00:00 ? 00:00:00 qmail-lspawn |dot-forward .forwa
qmailr 11735 11728 0 00:00 ? 00:00:00 qmail-rspawn
qmailq 11736 11728 0 00:00 ? 00:00:00 qmail-clean
qmaild 12697 11731 0 07:01 ? 00:00:00 /var/qmail/bin/qmail-smtpd
qmailq 12698 12697 0 07:02 ? 00:00:00 bin/qmail-queue
root 12703 12689 2 07:02 ? 00:00:00 sh -c (ps -ef|grep qmail) 2>&1
root 12704 12703 0 07:02 ? 00:00:00 sh -c (ps -ef|grep qmail) 2>&1
root 12706 12704 0 07:02 ? 00:00:00 grep qmail

cferchoff@accesscomm.ca (Curtis) writes:

>> What does "ps -ef|grep qmail" say?
>
> This is what I get:
>
>> ps -ef|grep qmail
> root 11724 11721 0 00:00 ? 00:00:00 supervise qmail-send
> root 11726 11721 0 00:00 ? 00:00:00 supervise qmail-smtpd
> qmails 11728 11724 0 00:00 ? 00:00:02 qmail-send
> qmaill 11729 11725 0 00:00 ? 00:00:00 /usr/local/bin/multilog t s25000
> qmaill 11730 11727 0 00:00 ? 00:00:00 /usr/local/bin/multilog t s25000
> qmaild 11731 11726 0 00:00 ? 00:00:00 /usr/local/bin/tcpserver -P -v -
> root 11734 11728 0 00:00 ? 00:00:00 qmail-lspawn |dot-forward .forwa
> qmailr 11735 11728 0 00:00 ? 00:00:00 qmail-rspawn
> qmailq 11736 11728 0 00:00 ? 00:00:00 qmail-clean
> qmaild 12697 11731 0 07:01 ? 00:00:00 /var/qmail/bin/qmail-smtpd
> qmailq 12698 12697 0 07:02 ? 00:00:00 bin/qmail-queue
> root 12703 12689 2 07:02 ? 00:00:00 sh -c (ps -ef|grep qmail) 2>&1
> root 12704 12703 0 07:02 ? 00:00:00 sh -c (ps -ef|grep qmail) 2>&1
> root 12706 12704 0 07:02 ? 00:00:00 grep qmail

That looks OK. How about:

svstat /service/* /service/*/log

--
Dave Sill Oak Ridge National Lab, Workstation Support
Author, The qmail Handbook <http://web.infoave.net/~dsill>
<http://lifewithqmail.org/>: Almost everything you always wanted to know.

Dave Sill <MaxFreedom@sws5.ctd.ornl.gov> wrote in message news:<wx0k7aiiojl.fsf@sws5.ornl.gov>...
> cferchoff@accesscomm.ca (Curtis) writes:
>
> >> What does "ps -ef|grep qmail" say?
> >
> > This is what I get:
> >
> >> ps -ef|grep qmail
> > root 11724 11721 0 00:00 ? 00:00:00 supervise qmail-send
> > root 11726 11721 0 00:00 ? 00:00:00 supervise qmail-smtpd
> > qmails 11728 11724 0 00:00 ? 00:00:02 qmail-send
> > qmaill 11729 11725 0 00:00 ? 00:00:00 /usr/local/bin/multilog t s25000
> > qmaill 11730 11727 0 00:00 ? 00:00:00 /usr/local/bin/multilog t s25000
> > qmaild 11731 11726 0 00:00 ? 00:00:00 /usr/local/bin/tcpserver -P -v -
> > root 11734 11728 0 00:00 ? 00:00:00 qmail-lspawn |dot-forward .forwa
> > qmailr 11735 11728 0 00:00 ? 00:00:00 qmail-rspawn
> > qmailq 11736 11728 0 00:00 ? 00:00:00 qmail-clean
> > qmaild 12697 11731 0 07:01 ? 00:00:00 /var/qmail/bin/qmail-smtpd
> > qmailq 12698 12697 0 07:02 ? 00:00:00 bin/qmail-queue
> > root 12703 12689 2 07:02 ? 00:00:00 sh -c (ps -ef|grep qmail) 2>&1
> > root 12704 12703 0 07:02 ? 00:00:00 sh -c (ps -ef|grep qmail) 2>&1
> > root 12706 12704 0 07:02 ? 00:00:00 grep qmail
>
> That looks OK. How about:
>
> svstat /service/* /service/*/log

Here is my output:

> svstat /service/* /service/*/log
/service/qmail-send: up (pid 11728) 41320 seconds
/service/qmail-smtpd: up (pid 11731) 41320 seconds
/service/qmail-send/log: up (pid 11729) 41320 seconds
/service/qmail-smtpd/log: up (pid 11730) 41320 seconds

Dave Sill <MaxFreedom@sws5.ctd.ornl.gov> wrote in message news:<wx0y8yygvnq.fsf@sws5.ornl.gov>...
> cferchoff@accesscomm.ca (Curtis) writes:
>
> > I've inherited a mail server at my work that is sending mail very
> > slowly. It takes 2-3 minutes to send a message, and when I check the
> > log, it is a 2mb file that has a number and then "alert: cannot start:
> > qmail-send is already running" for the whole log.
>
> From the information you've provided, everything seems to be up and
> running. Now we need to see where the delay is coming from, and find
> out what is trying to restart qmail-send and stop it.
>
> Post a snippet of the qmail-send logs that you've passed through
> tai64nlocal--just ten lines or so.
>
> Does "grep -v alert /var/log/qmail/current" show any "real" log
> entries? If so, look at the set of entries for a single message and
> post them if you can't see where the delay is occurring.


Here is a message when I do the "grep -v alert" command:

@400000003f15c30e3508ba94 new msg 45580
@400000003f15c30e35212c64 info msg 45580: bytes 1018 from
<christine.pirlot@brennansupply.com> qp 19649 uid 502
@400000003f15c30e356d259c starting delivery 316: msg 45580 to remote
ebissonnette@sgi.sk.ca
@400000003f15c30e356d8744 status: local 0/100 remote 1/100
@400000003f15c31014212514 delivery 316: success:
209.148.220.152_accepted_message./Remote_host_said:_250_Ok/
@400000003f15c310142186bc status: local 0/100 remote 0/100
@400000003f15c3101421965c end msg 45580


When I do the tai64nlocal command, this is what I get:


2003-07-14 14:20:08.916384500 alert: cannot start: unable to read
controls
2003-07-14 14:20:08.971977500 alert: cannot start: unable to read
controls
2003-07-14 14:20:09.023077500 alert: cannot start: unable to read
controls
2003-07-14 14:20:09.074973500 alert: cannot start: unable to read
controls
2003-07-14 14:20:09.127190500 alert: cannot start: unable to read
controls
2003-07-14 14:20:09.179000500 alert: cannot start: unable to read
controls
2003-07-14 14:20:09.232558500 alert: cannot start: unable to read
controls
2003-07-14 14:20:09.284363500 alert: cannot start: unable to read
controls
2003-07-14 14:20:09.336057500 alert: cannot start: unable to read
controls
2003-07-14 14:20:09.387476500 alert: cannot start: unable to read
controls
2003-07-14 14:20:09.440485500 alert: cannot start: unable to read
controls
2003-07-14 14:20:09.492384500 alert: cannot start: unable to read
controls
2003-07-14 14:20:09.544130500 alert: cannot start: unable to read
controls
2003-07-14 14:20:09.595414500 alert: cannot start: unable to read
controls
2003-07-14 14:20:09.646462500 alert: cannot start: unable to read
controls
2003-07-14 14:20:09.699508500 alert: cannot start: unable to read
controls
2003-07-14 14:20:09.749883500 alert: cannot start: unable to read
controls
2003-07-14 14:20:09.803727500 alert: cannot start: unable to read
controls


When I look at the file, these alerts are in the middle of the
"current" file and the beginning and end are entries like this:

2003-07-16 10:25:01.627917500 new msg 45580
2003-07-16 10:25:01.629503500 info msg 45580: bytes 1231 from
<support@brennansupply.com> qp 15498 uid 502
2003-07-16 10:25:01.633486500 starting delivery 220: msg 45580 to
remote cferchoff@accesscomm.ca
2003-07-16 10:25:01.633579500 status: local 0/100 remote 1/100
2003-07-16 10:25:03.078648500 delivery 220: success:
204.83.142.82_accepted_message./Remote_host_said:_250_ok_1058372704_qp_6152/
2003-07-16 10:25:03.079068500 status: local 0/100 remote 0/100
2003-07-16 10:25:03.079268500 end msg 45580


I guess I posted the wrong error in the first place, but the
qmail-send is still really slow.

Dave Sill <MaxFreedom@sws5.ctd.ornl.gov> wrote in message news:<wx0el0pl2nk.fsf@sws5.ornl.gov>...
> cferchoff@accesscomm.ca (Curtis) writes:
>
> > 2003-07-16 10:25:01.627917500 new msg 45580
> > 2003-07-16 10:25:01.629503500 info msg 45580: bytes 1231 from
> > <support@brennansupply.com> qp 15498 uid 502
> > 2003-07-16 10:25:01.633486500 starting delivery 220: msg 45580 to
> > remote cferchoff@accesscomm.ca
> > 2003-07-16 10:25:01.633579500 status: local 0/100 remote 1/100
> > 2003-07-16 10:25:03.078648500 delivery 220: success:
> > 204.83.142.82_accepted_message./Remote_host_said:_250_ok_1058372704_qp_6152/
> > 2003-07-16 10:25:03.079068500 status: local 0/100 remote 0/100
> > 2003-07-16 10:25:03.079268500 end msg 45580
> >
> > I guess I posted the wrong error in the first place, but the
> > qmail-send is still really slow.
>
> That shows that it took qmail less than two seconds to send a message
> to a remote host. What, exactly, are you seeing that's slow?

When you send a message in Outlook Express or Outlook, the program
says that it is "Connecting" for a long time, and if the server
timeout option isn't set higher, it times out. Essentially, you have
to wait a long time until the message is sent. When you take messages
off of the server with Outlook or Outlook Express, it is
instantaneous.

Sorry I didn't explain the situation clearly to begin with.

cferchoff@accesscomm.ca (Curtis) writes:

> When you send a message in Outlook Express or Outlook, the program
> says that it is "Connecting" for a long time, and if the server
> timeout option isn't set higher, it times out. Essentially, you have
> to wait a long time until the message is sent. When you take messages
> off of the server with Outlook or Outlook Express, it is
> instantaneous.

This is a FAQ. See:

http://lifewithqmail.org/lwq.html#smtp-slow

--
Dave Sill Oak Ridge National Lab, Workstation Support
Author, The qmail Handbook <http://web.infoave.net/~dsill>
<http://lifewithqmail.org/>: Almost everything you always wanted to know.