Mailing List CGatePro@mail.stalker.com Message #100488
From: Kee Hinckley <nazgul@somewhere.com>
Subject: 532 access from your network is restricted, try later
Date: Tue, 03 Aug 2010 06:21:16 -0700
To: <CGatePro>
X-Mailer: Apple Mail (2.1081)
Here's the problem. My mail server is under heavy load (stats in a moment). An authenticated user attempts to send mail on the submit port. I've reserved slots for authenticated users, but you can't reserve them by *port*, so apparently they share resources with whatever comes in on port 25. For whatever reason, CGP "randomly" tells the user to go away with the bogus error: "532 access from your network is restricted, try later". This started happening a couple weeks ago, prior to that it had been running fine for 10 months, and I haven't touched the settings for nearly as long. Sometimes they get this error immediately after sending previous mail. Sometimes they get it the first time they connect. Sometimes they've fetched mail first. Sometimes they haven't. It has all appearances of being a resource problem, but a) there shouldn't be a resource problem for authenticated users and b) that's the wrong error message. See the log at the bottom for details.

At this point the only solution I can think of is to reduce the load on my machine by putting a graylisting server in-front of it. I'd *really* rather not complicate my situation by adding a whole piece of non-CGP software on a dedicated machine. I use CGP because it answers all my problems in one easy package. Furthermore, this looks like a DoS problem that any CGP installation could suffer from, and that's not good news for anybody.

So here are my SMTP Receiving settings:
850 Channels*
Advertise AUTH to everybody, ditto 8bitmime
Verify return-path for non-clients, help for non-clients.
I've turned off SPF (it was blocking a minuscule number of messages)
I've disabled Reverse Connect
Message Limits 100M
Recipients 100
Non-Client Sender:
Recipients 5 in 30 seconds
Delay prompt for 0 seconds (delays flood my queue)
Disconnect after 1 error and deny access for 0 seconds**
Listener
Init SSL/TLS off on 25, off on 587, on on 465
Limit connections from same address is 3
Reserve connections for Clients is 10***

* I can't pump it up to more than 850 channels without running out of sockets. I could configure the machine with more, but the spam flow is only increasing, so it's just a matter of time before I hit the problem again.
**I had set deny access to 5 minutes, but then I got reports that when a user got the 532 error, they couldn't *fetch* mail either, so until I've solved this problem, I've had to put it at 0 seconds.
*** The reserved connections may seem low, but I have a minimal license. I'm not getting more than 10 authenticated clients at a time. And I've tried 30, that didn't help.

Server Info
Main Domain Name:somewhere.com
Server Internals Log:
Crash Recovery:
Separate WebAdmin Realms:
Server Time:Thu, 29 Jul 2010 17:33:06 -0400
Server Up-time:13 day(s) 7 hour(s) 55 min 13 sec
Server OS:Linux 
Server Hardware:x86-64 (64-bit) 
Server Version:5.2.16
MAPI Version:1.52.15.3
IPv6 Support:Disabled
Name Server(s) IP Address(es):[8.8.8.8], [8.8.4.4]
Server IP Address(es):
[127.0.0.1] somewhere.com
[136.248.126.131] somewhere.com
FWIW, I'm running the Debian version of CGP on Ubuntu.


So what's my load that's causing this problem? Here's a snapshot.


I'm processing about 25-30 SMTP connections per-second. 99% of them are rejected.




Here are the log files. I've sanitized the email addresses.

First connection from 136.248.126.131, we trust them (because I trust IPs where authentication has occurred in the last several hours). Mail is delivered just fine.

14:38:16.099 5 SMTP [136.248.126.131]:587 <- [71.174.98.115]:55128 connection request. socket=426
14:38:16.099 4 SMTPI-659595([71.174.98.115]) got connection on [136.248.126.131]:587(somewhere.com) from [71.174.98.115]:55128
14:38:16.099 5 SMTPI-659595([71.174.98.115]) out: 220 somewhere.com ESMTP CommuniGate Pro 5.2.16 is glad to see you!\r\n
14:38:16.149 5 SMTPI-659595([71.174.98.115]) inp: EHLO [172.16.1.141]
14:38:16.149 5 SMTPI-659595([71.174.98.115]) out: 250-somewhere.com we trust you [172.16.1.141]\r\n250-DSN\r\n250-SIZE 104857600\r\n250-STARTTLS\r\n250-AUTH LOGIN PLAIN CRAM-MD5 DIGEST-MD5 GSSAPI MSN NTLM\r\n250-ETRN\r\n250-TURN\r\n250-ATRN\r\n250-NO-SOLICITING\r\n250-8BITMIME\r\n250-HELP\r\n250-PIP
14:38:16.194 5 SMTPI-659595([71.174.98.115]) inp: AUTH CRAM-MD5
14:38:16.194 5 SMTPI-659595([71.174.98.115]) SASL-0(CRAM-MD5) out: <659595.1279305496@somewhere.com>
14:38:16.194 5 SMTPI-659595([71.174.98.115]) out: 334 PDY1OTU5NS4xMjc5MzA1NDk2QHNvbWV3aGVyZS5jb20+\r\n
14:38:16.244 5 SMTPI-659595([71.174.98.115]) inp: bmF6Z3VsIDFhYjljNjkzZDgyM2U2YmRmMmEzNzYyM2QzMGI5OTg4
14:38:16.244 5 SMTPI-659595([71.174.98.115]) SASL-0(CRAM-MD5) inp: YYY 1ab9c693d823e6bdf2a37623d30b9988
14:38:16.245 2 SMTPI-659595([71.174.98.115]) 'YYY@somewhere.com' connected from [71.174.98.115]:55128(temp client)
14:38:16.245 2 SMTPI-659595([71.174.98.115]) 'YYY@somewhere.com' disconnected ([71.174.98.115]:55128)
14:38:16.245 5 SMTPI-659595([71.174.98.115]) out: 235 YYY relaying authenticated\r\n
14:38:16.294 5 SMTPI-659595([71.174.98.115]) inp: MAIL FROM:<ZZZ@example.com>
14:38:16.294 5 SMTPI-659595([71.174.98.115]) out: 250 ZZZ@example.com sender accepted\r\n
14:38:16.342 5 SMTPI-659595([71.174.98.115]) inp: RCPT TO:<XXX@gmail.com>
14:38:16.342 5 SMTPI-659595([71.174.98.115]) out: 250 XXX@gmail.com will relay mail for an authenticated user\r\n
14:38:16.409 5 SMTPI-659595([71.174.98.115]) inp: DATA
14:38:16.409 5 SMTPI-659595([71.174.98.115]) out: 354 Enter mail, end with "." on a line by itself\r\n
14:38:16.467 2 SMTPI-659595([71.174.98.115]) [7780603] received(YYY), 1146 bytes
14:38:16.467 5 SMTPI-659595([71.174.98.115]) out: 250 7780603 message accepted for delivery\r\n
14:38:17.850 5 SMTP-000114(gmail.com) out: Received: from [71.174.98.115] (account YYY HELO [172.16.1.141])\r\n  by somewhere.com (CommuniGate Pro SMTP 5.2.16)\r\n  with ESMTPA id 7780603 for XXX@gmail.com; Fri, 16 Jul 2010 14:38:16 -0400\r\nContent-Type: text/plain; charset=us-ascii\r\nMime
14:39:16.733 5 SMTPI-659595([71.174.98.115]) inp: QUIT
14:39:16.733 5 SMTPI-659595([71.174.98.115]) out: 221 somewhere.com CommuniGate Pro SMTP closing connection\r\n
14:39:16.733 4 SMTPI-659595([71.174.98.115]) closing connection
14:39:16.733 4 SMTPI-659595([71.174.98.115]) releasing stream

50 seconds later. Another SMTP connection from the same user and same IP. (In between there have been plenty of spam connections, but nothing on port 587. Still trusted, but we get "532 access from your network is restricted, try later" instead. Annoyingly, Apple's mail products (Mac and iPhone) interpret this as "incorrect password", which led me on a wild goose chase for some time, never mind making the process of resubmitting (re-enter password every time) a royal pain.

14:39:56.205 5 SMTP [136.248.126.131]:587 <- [71.174.98.115]:55157 connection request. socket=293
14:39:56.205 4 SMTPI-663062([71.174.98.115]) got connection on [136.248.126.131]:587(somewhere.com) from [71.174.98.115]:55157
14:39:56.205 5 SMTPI-663062([71.174.98.115]) out: 220 somewhere.com ESMTP CommuniGate Pro 5.2.16 is glad to see you!\r\n
14:39:56.263 5 SMTPI-663062([71.174.98.115]) inp: EHLO [172.16.1.141]
14:39:56.263 5 SMTPI-663062([71.174.98.115]) out: 250-somewhere.com we trust you [172.16.1.141]\r\n250-DSN\r\n250-SIZE 104857600\r\n250-STARTTLS\r\n250-AUTH LOGIN PLAIN CRAM-MD5 DIGEST-MD5 GSSAPI MSN NTLM\r\n250-ETRN\r\n250-TURN\r\n250-ATRN\r\n250-NO-SOLICITING\r\n250-8BITMIME\r\n250-HELP\r\n250-PIP
14:39:56.310 5 SMTPI-663062([71.174.98.115]) inp: AUTH CRAM-MD5
14:39:58.307 5 SMTPI-663062([71.174.98.115]) out: 532 access from your network is restricted, try later\r\n
14:39:58.350 3 SMTPI-663062([71.174.98.115]) read failed. Error Code=connection closed by peer
14:39:58.350 4 SMTPI-663062([71.174.98.115]) closing connection
14:39:58.350 4 SMTPI-663062([71.174.98.115]) releasing stream

And again, 4 seconds later.

14:40:02.618 5 SMTP [136.248.126.131]:587 <- [71.174.98.115]:55158 connection request. socket=266
14:40:02.618 4 SMTPI-663276([71.174.98.115]) got connection on [136.248.126.131]:587(somewhere.com) from [71.174.98.115]:55158
14:40:02.618 5 SMTPI-663276([71.174.98.115]) out: 220 somewhere.com ESMTP CommuniGate Pro 5.2.16 is glad to see you!\r\n
14:40:02.671 5 SMTPI-663276([71.174.98.115]) inp: EHLO [172.16.1.141]
14:40:02.671 5 SMTPI-663276([71.174.98.115]) out: 250-somewhere.com we trust you [172.16.1.141]\r\n250-DSN\r\n250-SIZE 104857600\r\n250-STARTTLS\r\n250-AUTH LOGIN PLAIN CRAM-MD5 DIGEST-MD5 GSSAPI MSN NTLM\r\n250-ETRN\r\n250-TURN\r\n250-ATRN\r\n250-NO-SOLICITING\r\n250-8BITMIME\r\n250-HELP\r\n250-PIP
14:40:02.719 5 SMTPI-663276([71.174.98.115]) inp: AUTH CRAM-MD5
14:40:04.719 5 SMTPI-663276([71.174.98.115]) out: 532 access from your network is restricted, try later\r\n
14:40:04.765 3 SMTPI-663276([71.174.98.115]) read failed. Error Code=connection closed by peer
14:40:04.765 4 SMTPI-663276([71.174.98.115]) closing connection
14:40:04.765 4 SMTPI-663276([71.174.98.115]) releasing stream

Eventually they can get through. But there's no rhyme or reason to it that I can see. They just have to keep trying until it works.


Kee Hinckley
Owner, Somewhere LLC.Somewhere: http://www.somewhere.com/TechnoSocial: http://xrl.us/bh35i


Subscribe (FEED) Subscribe (DIGEST) Subscribe (INDEX) Unsubscribe Mail to Listmaster