My apologies, everyone… tcpserver status code 256 apparently means that the client did not gracefully terminate the connection? So something is timing it out after 60 seconds. I tried a different client and a test message went right through, so it appears to be a client-side issue (Apple Mail on OS 11.1).
Sorry for spamming the list, but maybe this will help a future googler. :/ - Steve > On Jan 30, 2021, at 2:53 PM, Eric Broch <[email protected]> wrote: > > Try a different dns server > > On 1/30/21 12:25 PM, Steve Linberg wrote: >> Greetings all. I’ve been running qmail on my servers and vms for about 20 >> years and it’s mostly worked great, but I’m having a thumper of a slowdown >> problem on my current setup and I can’t get to the bottom of it… any help >> appreciated. >> >> The environment is a very lightly-used private VM running centos7 and the >> following packages: >> >> [root@radbug ~]# yum list installed | grep qmail >> qmail.x86_64 1.03-2.2.1.qt.el7 @qmt-current >> qmailadmin.x86_64 1.2.16-3.2.qt.el7 @qmt-current >> qmailmrtg.x86_64 4.2-3.qt.el7 @qmt-current >> >> I’ve narrowed it down to a delay shown in /var/log/qmail/submission/current, >> when I send a test message to myself at another address, using my vm as my >> mail server. The first lines hit immediately when I click “send” in the mail >> client, but then it takes a full minute between the tcpserver “end” message >> and whatever preceded it, during which time my mail client hangs at >> “sending…”: (annotations [*** like this ***] inline are mine, obviously, and >> addresses/servers replaced with caps but the IPs are unchanged): >> >> 2021-01-30 13:42:52.255716500 tcpserver: status: 0/100 >> [*** message sent......... ***] >> 2021-01-30 13:47:33.912724500 tcpserver: status: 1/100 >> 2021-01-30 13:47:33.912947500 tcpserver: pid 6009 from 24.62.203.29 >> 2021-01-30 13:47:33.912948500 tcpserver: ok 6009 MYHOST:104.236.46.99:587 >> :24.62.203.29::55124 >> [*** waiting... one minute 4 seconds pass ***] >> 2021-01-30 13:48:37.899374500 tcpserver: end 6009 status 256 >> 2021-01-30 13:48:37.899376500 tcpserver: status: 0/100 >> 2021-01-30 13:48:37.930988500 tcpserver: status: 1/100 >> 2021-01-30 13:48:37.931122500 tcpserver: pid 6021 from 24.62.203.29 >> 2021-01-30 13:48:37.931198500 tcpserver: ok 6021 MYHOST:104.236.46.99:587 >> :24.62.203.29::55129 >> 2021-01-30 13:48:38.263537500 CHKUSER accepted sender: from >> <[email protected] <mailto:[email protected]>:[email protected] >> <mailto:[email protected]>:> remote <[10.0.98.178]:unknown:24.62.203.29> >> rcpt <> : sender accepted >> 2021-01-30 13:48:38.327973500 CHKUSER relaying rcpt: from <[email protected] >> <mailto:[email protected]>:[email protected] <mailto:[email protected]>:> >> remote <[10.0.98.178]:unknown:24.62.203.29> rcpt <[email protected] >> <mailto:[email protected]>> : client allowed to relay >> 2021-01-30 13:48:38.327975500 policy_check: local [email protected] >> <mailto:[email protected]> -> remote [email protected] >> <mailto:[email protected]> (AUTHENTICATED SENDER) >> 2021-01-30 13:48:38.327976500 policy_check: policy allows transmission >> [*** waiting... (message received) then one more minute passes ***] >> 2021-01-30 13:49:38.403478500 tcpserver: end 6021 status 0 >> 2021-01-30 13:49:38.403479500 tcpserver: status: 0/100 >> >> It’s very consistent in this timing, and loads on the server are basically >> 0, nothing in /var/log/messages or anywhere else that I can see. Vpopmail is >> using mysql, but it isn’t logging any slow queries, and this is more or less >> the only thing happening on the box. It’s been doing it for a while now, >> maybe a month or two? I don’t send much mail so I didn’t lean into it too >> hard when it started happening, but now it’s really annoying me and I want >> to get to the bottom of it. (Inbound mail TO the server from other locations >> (like the auto response to the “subscribe” message I sent to the list just >> now) lands instantly.) >> >> My /etc/tcprules.d/tcp.smtp: (I thought it might have been something about >> domain keys, so I removed that but it hasn’t made any difference) >> 127.:allow,BADMIMETYPE="",BADLOADERTYPE="M",CHKUSER_RCPTLIMIT="50",CHKUSER_WRONGRCPTLIMIT="10",NOP0FCHECK="1",QMAILQUEUE="/var/qmail/bin/simscan" >> >> My /var/qmail/supervise/submission/run: >> #!/bin/sh >> >> >> QMAILDUID=`id -u vpopmail` >> NOFILESGID=`id -g vpopmail` >> MAXSMTPD=`cat /var/qmail/control/concurrencyincoming` >> SMTPD="/var/qmail/bin/qmail-smtpd" >> TCP_CDB="/etc/tcprules.d/tcp.smtp.cdb" >> HOSTNAME=`hostname` >> VCHKPW="/home/vpopmail/bin/vchkpw" >> export REQUIRE_AUTH=1 >> >> exec /usr/bin/softlimit -m 128000000 \ >> /usr/bin/tcpserver -v -R -H -l $HOSTNAME -x $TCP_CDB -c "$MAXSMTPD" \ >> -u "$QMAILDUID" -g "$NOFILESGID" 0 587 \ >> $SMTPD $VCHKPW /bin/true 2>&1 >> >> In case it’s relevant, my /var/qmail/supervise/smtp/run: >> #!/bin/sh >> >> >> QMAILDUID=`id -u vpopmail` >> NOFILESGID=`id -g vpopmail` >> MAXSMTPD=`cat /var/qmail/control/concurrencyincoming` >> SPAMDYKE="/usr/bin/spamdyke" >> SPAMDYKE_CONF="/etc/spamdyke/spamdyke.conf" >> SMTPD="/var/qmail/bin/qmail-smtpd" >> TCP_CDB="/etc/tcprules.d/tcp.smtp.cdb" >> HOSTNAME=`hostname` >> VCHKPW="/home/vpopmail/bin/vchkpw" >> REQUIRE_AUTH=0 >> >> exec /usr/bin/softlimit -m 64000000 \ >> /usr/bin/tcpserver -v -R -H -l $HOSTNAME -x $TCP_CDB -c "$MAXSMTPD" \ >> -u "$QMAILDUID" -g "$NOFILESGID" 0 smtp \ >> $SPAMDYKE --config-file $SPAMDYKE_CONF \ >> $SMTPD $VCHKPW /bin/true 2>&1 >> >> I tried removing spamdyke from this just to see if it made a difference >> after “qmailctl restart”; it didn’t make a difference. >> >> It’s very consistent in this timing, and loads on the server are basically >> 0, nothing in /var/log/messages or anywhere else that I can see. Vpopmail is >> using mysql, but it isn’t logging any slow queries, and this is more or less >> the only thing happening on the box. The mail does go out, but it always >> takes a minute to clear the outbox from my mail client, and I can’t figure >> out why it’s happening. >> >> Any advice or dope-slaps much appreciated. Going to click “send” on this now >> and wait one minute for it to get sent… >:-( >> >> >> >>
