Intermittent Send Error 0x800CCC0F

Problems/tips/tricks with MailWasher Enterprise, Windows and Exchange
mweddle
Rattled Rabbit
Posts: 3
Joined: Wed Oct 07, 2009 3:07 pm

Intermittent Send Error 0x800CCC0F

Wed Jan 06, 2010 3:31 pm

I've previously been using MailWasher Enterpriese 2.7.3 and 2.7.4 without error on Windows/Exchange 2000.

I've updated (repaved) my server (new hardware) to Windows Enterprise 2008 64 bit, Exchange 2010 (in-place beta), and reinstalled MailWasher Enterprise 2.7.3 with a later upgrade to 2.7.4.

I followed the instructions to proxy to a loopback port according to the installation instructions, and generally, things work out as they should.

However, I have found that sending email (Outlook 2007) to external destinations by authenticated users can quite often result in an exception reading from the port after a send on the close of the message transmission by Mailwasher, which results in a failure to the client. Although the message was sent, the error is sent back to the client, and the client will continue to retry until it is successful. On average, it will take 3-10 attempts before this occurs, resulting in the receiver of the messages getting duplicates.

There are no errors in the event log or the Mailwasher log at all other than described. Mail can be received, users authenticated, and same-domain email sent without issues. I've included a snippet of the log that indicates the "trailing error" that causes this failure (with some changes to remove IP and personal names/email addresses/computer names). Due to the non-deterministic failure rate of the error (1 in 10 works first time), it's difficult to say where the error lies. I have disabled all Firewall and Anti-virus applications on both the server and the client in an attempt to isolate the issue, and have stripped down security permissions on anything I can get my hands on in the Exchange management tools, with no change in behavior.

It's important to restate that even in the error cases, the message is sent correctly.

Any ideas why this might be happening? I could find nothing like it in the forums or abroad.

Thanks!

mw

Changed email addresses, computer names, and ips consistently; log level 1
Manual start and stop of service
--------------------------------------------------------------------------------------
2010-01-05 18:10:33 [11760] Info: starting mwes version 2.7.4 {W}
2010-01-05 18:10:33 [11760] Info: environment....
2010-01-05 18:10:33 [11760] Info: cfs_max_cache_size::20000
2010-01-05 18:10:33 [11760] Info: database_location::C:\Program Files\MailWasher Enterprise Server\data
2010-01-05 18:10:33 [11760] Info: default_page::Quarantined.srv
2010-01-05 18:10:33 [11760] Info: home::C:\Program Files\MailWasher Enterprise Server
2010-01-05 18:10:33 [11760] Info: listen_port::4044
2010-01-05 18:10:33 [11760] Info: log_level::1
2010-01-05 18:10:33 [11760] Info: logging::C:\Program Files\MailWasher Enterprise Server\logs
2010-01-05 18:10:33 [11760] Info: mta_hostname::127.0.0.1
2010-01-05 18:10:33 [11760] Info: mta_port::25
2010-01-05 18:10:33 [11760] Info: proxy_hostname::1.2.3.4
2010-01-05 18:10:33 [11760] Info: proxy_port::25
2010-01-05 18:10:33 [11760] Info: rbl_max_cache_size::20000
2010-01-05 18:10:33 [11760] Info: root_document::C:\Program Files\MailWasher Enterprise Server\site
2010-01-05 18:10:33 [11760] Info: use_check_domains::1
2010-01-05 18:10:33 [11760] Info: use_mta_proxy::1
2010-01-05 18:10:33 [11760] Info: web_hostname::localhost
2010-01-05 18:10:33 [11760] Info: web_port::4044
2010-01-05 18:10:33 [11760] Info: Initialising WebManager....
2010-01-05 18:10:33 [11760] Info: Initialising database....
2010-01-05 18:10:33 [11760] Info: Initialising database configure table....
2010-01-05 18:10:33 [11760] Info: DatabaseManager::UpgradeDatabase - version 19 ok
2010-01-05 18:10:33 [11760] Info: Initialising database configure table....
2010-01-05 18:10:33 [11760] Info: Initialising database white listing table....
2010-01-05 18:10:33 [11760] Info: Initialising database black listing table....
2010-01-05 18:10:33 [11760] Info: Initialising database filter black listing table....
2010-01-05 18:10:33 [11760] Info: Initialising database rbl listing table....
2010-01-05 18:10:33 [11760] Info: Initialising database quarantined table....
2010-01-05 18:10:33 [11760] Info: Initialising database gray listing table....
2010-01-05 18:10:33 [11760] Info: Initialising database white listing ip table....
2010-01-05 18:10:33 [11760] Info: Initialising database black listing ip table....
2010-01-05 18:10:33 [11760] Info: Initialising database user table....
2010-01-05 18:10:33 [11760] Info: Initialising database Gray listing friends table....
2010-01-05 18:10:33 [11760] Info: Initialising database Domain table....
2010-01-05 18:10:33 [11760] Info: Initialising Auto-reporting....
2010-01-05 18:10:33 [11760] Info: Starting StatThread....
2010-01-05 18:10:33 [11760] Info: Starting FilterManagerThreads....
2010-01-05 18:10:33 [6712] Info: Starting TaskThread....
2010-01-05 18:10:33 [11760] Info: Starting UploadManagerThread....
2010-01-05 18:10:33 [11760] Info: Starting MTA proxy....
2010-01-05 18:10:33 [11760] Info: Starting HouseKeepingTask....
2010-01-05 18:10:33 [2224] Debug: Login::VersionStatusCollect - http://www.firetrust.com/sites/firetrus ... ion.xml:80
2010-01-05 18:10:34 [2224] Debug: HTTPSocket::HTTPSocket - HTTP/1.1 200 OK
2010-01-05 18:10:34 [2224] Debug: HTTPSocket::HTTPSocket - Date: Wed, 06 Jan 2010 02:11:01 GMT
2010-01-05 18:10:34 [2224] Debug: HTTPSocket::HTTPSocket - Server: Apache/2.2.9 (Debian) PHP/5.2.6-1+lenny4 with Suhosin-Patch mod_python/3.3.1 Python/2.5.2 mod_ssl/2.2.9 OpenSSL/0.9.8g mod_perl/2.0.4 Perl/v5.10.0
2010-01-05 18:10:34 [2224] Debug: HTTPSocket::HTTPSocket - Last-Modified: Mon, 28 Sep 2009 21:06:19 GMT
2010-01-05 18:10:34 [2224] Debug: HTTPSocket::HTTPSocket - ETag: "3c8016-ab-474a9ab4ba8c0"
2010-01-05 18:10:34 [2224] Debug: HTTPSocket::HTTPSocket - Accept-Ranges: bytes
2010-01-05 18:10:34 [2224] Debug: HTTPSocket::HTTPSocket - Content-Length: 171
2010-01-05 18:10:34 [2224] Debug: HTTPSocket::HTTPSocket - Content-Type: application/xml
2010-01-05 18:10:34 [2224] Debug: HTTPSocket::HTTPSocket -
2010-01-05 18:10:34 [2224] Debug: VersionStatus::Collect - xml size(171)

<mwes>

<VersionNumber>2.7.4</VersionNumber>

<VersionURL>http://www.firetrust.com/en/products/ma ... VersionURL>

</mwes>
2010-01-05 18:10:45 [6040] Debug: SMTPChannel::Create - new 1
2010-01-05 18:10:45 [12020] Debug: SMTPChannel::PutClientLine: From Relay(127.0.0.1) To Client IP(1.2.3.4) 220 example.com Microsoft ESMTP MAIL Service ready at Tue, 5 Jan 2010 18:10:44 -0800
2010-01-05 18:10:45 [12020] Debug: SMTPChannel::GetClientLine: AUTH LOGIN
2010-01-05 18:10:45 [12020] Debug: SMTPChannel::PutClientLine: From Relay(127.0.0.1) To Client IP(1.2.3.4) 334 blahblah
2010-01-05 18:10:45 [12020] Debug: SMTPChannel::GetClientLine: blahblahresponse
2010-01-05 18:10:45 [12020] Debug: SMTPChannel::PutClientLine: From Relay(127.0.0.1) To Client IP(1.2.3.4) 334 anotherblahblah
2010-01-05 18:10:45 [12020] Debug: SMTPChannel::GetClientLine: anotherblahblahresponse
2010-01-05 18:10:45 [12020] Debug: SMTPChannel::PutClientLine: From Relay(127.0.0.1) To Client IP1.2.3.4) 235 2.7.0 Authentication successful
2010-01-05 18:10:45 [12020] Debug: SMTPChannel::GetClientLine: MAIL FROM: <user@example.com>
2010-01-05 18:10:45 [12020] Debug: SMTPChannel::PutClientLine: From Relay(127.0.0.1) To Client IP(1.2.3.4) 250 2.1.0 Sender OK
2010-01-05 18:10:45 [12020] Debug: SMTPChannel::GetClientLine: RCPT TO: <user@another_example.com>
2010-01-05 18:10:45 [12020] Debug: SMTPChannel::PutClientLine: From Relay(127.0.0.1) To Client IP(1.2.3.4) 250 2.1.5 Recipient OK
2010-01-05 18:10:45 [12020] Debug: SMTPChannel::GetClientLine: DATA
2010-01-05 18:10:45 [12020] Debug: SMTPChannel::PutClientLine: From Relay(127.0.0.1) To Client IP(1.2.3.4) 354 Start mail input; end with <CRLF>.<CRLF>
2010-01-05 18:10:45 [12020] Debug: Authenticated by MTA 5.6.7.8,computerName,<user@example.com>, <user@another_example.com>]
2010-01-05 18:10:55 [12020] Debug: SMTPChannel::ObjectThreadMethod - TCPSocketTimeoutException - TCPSocket::SelectReadWrite - timed out (10000) while reading from the socket on (127.0.0.1)() failed with code 10060: A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond.
2010-01-05 18:10:58 [11760] Info: Shutdown Auto-reporting....
2010-01-05 18:10:58 [11760] Info: Shutdown HouseKeepingTask....
2010-01-05 18:10:58 [11760] Info: Shutdown WebManager....
2010-01-05 18:10:59 [11760] Info: Shutdown MTA proxy....
2010-01-05 18:10:59 [11760] Info: Shutdown FilterManagerThreads....
2010-01-05 18:10:59 [11976] Debug: Successfully disconnected from CFS...
2010-01-05 18:10:59 [11976] Info: FilterManagerThread::ObjectThreadMethod - ending
2010-01-05 18:10:59 [11760] Info: Shutdown UploadManagerThread....
2010-01-05 18:10:59 [5568] Debug: Successfully disconnected from CFS...
2010-01-05 18:10:59 [5568] Info: UploadManagerThread::ObjectThreadMethod - ending
2010-01-05 18:10:59 [11760] Info: Shutdown StatThread....
2010-01-05 18:10:59 [11760] Info: Close database....
2010-01-05 18:10:59 [11760] Info: Ending MWES....
cliff
Evil Firetrust Employee
Posts: 31
Joined: Tue Jul 28, 2009 3:50 pm

Re: Intermittent Send Error 0x800CCC0F

Sun Jan 10, 2010 4:01 pm

Hi There,

The error you have presented indicates a dropped connection (without closing the socket) by Exchange.

I would recomend upgrading to the release version of Exchange 2010, as a beta is often prone to issues (it's the idea of a beta).
I have tested MWES with the release version of Exchange 2010 without issue.
mweddle
Rattled Rabbit
Posts: 3
Joined: Wed Oct 07, 2009 3:07 pm

Re: Intermittent Send Error 0x800CCC0F

Thu Jan 14, 2010 6:11 pm

Apologies, I may have used the "Beta" reference a little too quickly. I was under the impression when I was installing it from the MSDN download, that it was very close to RTM and would be upgraded in place with merely a product key. However, I can find no trace of anything like that now, and I haven't updated it.

The version Exchange 2010 indicates from the management console is 14.00.0639.021, and the KB article at MS indicates this is the RTM version.

Let me continue to test and check and see if I can find anything more about it. Any suggestions or guidance would be welcome.
cliff
Evil Firetrust Employee
Posts: 31
Joined: Tue Jul 28, 2009 3:50 pm

Re: Intermittent Send Error 0x800CCC0F

Tue Jan 19, 2010 12:10 pm

Hi there,

An easy way may be to confirm he download file name.
The current MSDN download is labelled: mu_exchange_server_2010_x64_dvd_x15-82068.iso with the date: 11/9/2009 (American format).
I tested a beta myself a while back, and it did not require a key to install (keys weren't even available at the time). Once the RTM was released the keys were immediately available. This may help with the time frame of installation?

The debug log you've posted below is incomplete and altered. There is missing data that you have edited or changed so we can not effectively see what's happening at all staged of the SMTP conversation.
Can you please post a complete unedited log, or if you're not comfortable posting it, please email it to: cliff@firetrust.com for analysis.
Last edited by cliff on Mon Oct 12, 2015 10:50 pm, edited 1 time in total.
mweddle
Rattled Rabbit
Posts: 3
Joined: Wed Oct 07, 2009 3:07 pm

Re: Intermittent Send Error 0x800CCC0F

Tue Jan 19, 2010 2:56 pm

Indeed, as the notes indicate I changed some of the information to reduce spam uptake of email and IP addresses.

That said, after about three months of these difficulties and no Windows/product updates, or configuration changes, I'm not seeing the error anymore.

It could as easily appear as it has vanished, so I'll send the log along to the email address provided in case it is seen somewhere else, or shows again.

Return to “Windows Specific”