possible bug? failed authentication but mail sent

Use this forum if you have installed hMailServer and want to ask a question related to a production release of hMailServer. Before posting, please read the troubleshooting guide. A large part of all reported issues are already described in detail here.
Post Reply
magicmonkey
New user
New user
Posts: 1
Joined: 2005-07-09 13:33

possible bug? failed authentication but mail sent

Post by magicmonkey » 2005-07-09 13:41

As far as I'm awear I have the security settings correct but when asked for authentication for the SMTP server I can enter in any password and still send mail. The log is below, the first message was sent using the incorect password. The second uses the correct password. When the incorrect password is used the message Authentication failed. Restarting authentication process." is displayed in the log however the mail is still sent. I am using thunderbird as my email client. Perhaps it caches previous passwords, though the log doesn't indicate a correct authentication.

********************************First message with incorrect password******************************************************
"TCPIP" 1988 "2005-07-09 12:18:06.737" "SMTPD - Connection from 192.168.1.2 accepted."
"DEBUG" 1948 "2005-07-09 12:18:06.737" "SocketConnection::SocketConnection()"
"SMTPD" 1948 "2005-07-09 12:18:06.737" "192.168.1.2" "SENT: 220 ******.dyndns.org ESMTP hMailServer 3.4.1-B86 "
"SMTPD" 1948 "2005-07-09 12:18:06.747" "192.168.1.2" "RECEIVED: EHLO [192.168.1.2]"
"SMTPD" 1948 "2005-07-09 12:18: 06.747" "192.168.1.2" "SENT: 250-hmailserver[nl]250 AUTH LOGIN"
"SMTPD" 1948 "2005-07-09 12:18:06.757" "192.168.1.2 " "RECEIVED: AUTH LOGIN"
"SMTPD" 1948 "2005-07-09 12:18:06.757" "192.168.1.2" "SENT: 334 VXNlcm5hbWU6"
"SMTPD" 1948 "2005-07-09 12:18: 06.767" "192.168.1.2" "RECEIVED: dGVzdEB1cmZtYWlsLmR5bmRucy5vcmc="
"SMTPD" 1948 "2005-07-09 12:18:06.767" " 192.168.1.2" "SENT: 334 UGFzc3dvcmQ6"
"SMTPD" 1948 "2005-07-09 12:18:06.777" "192.168.1.2" "RECEIVED: bm9wYXNzd29yZA=="
"SMTPD" 1948 "2005-07-09 12:18: 06.777" "192.168.1.2" "SENT: 535 Authentication failed. Restarting authentication process."
"SMTPD" 1948 "2005-07-09 12:18:06.787" " 192.168.1.2" "RECEIVED: MAIL FROM: <test@******.dyndns.org>"
"SMTPD" 1948 "2005-07-09 12:18:06.787" " 192.168.1.2" "SENT: 250 test@******.dyndns.org... Sender OK"
"SMTPD" 1948 "2005-07-09 12:18:06.787" " 192.168.1.2" "RECEIVED: RCPT TO: <******@gmail.com>"
"SMTPD" 1948 "2005-07-09 12:18:06.797" "192.168.1.2 " "SENT: 250 OK its for ******@gmail.com"
"SMTPD" 1948 "2005-07-09 12:18:06.797" "192.168.1.2" "RECEIVED: DATA"
"SMTPD" 1948 "2005-07-09 12:18:06.797" "192.168.1.2" "SENT: 354 ok send! end with <crlf>.<crlf>"
"DEBUG" 1948 "2005-07-09 12:18: 06.967" "Message added. File: C:\Program Files\hMailServer\Data\{EE8A9995-24F4-4705-AA79-32763F2AD3B1}.eml"
"SMTPD" 1948 "2005-07-09 12:18:06.967" "192.168.1.2 " "SENT: 250 Message queued (0.170 seconds)"
"SMTPD" 1948 "2005-07-09 12:18:07.067" "192.168.1.2" "RECEIVED: QUIT"
"DEBUG" 1948 "2005-07-09 12:18: 07.067" "Messages::Save()"
"DEBUG" 1948 "2005-07-09 12:18:07.067" "Messages::Save() - Message iteration."
"DEBUG" 1948 "2005-07-09 12:18:07.067" "PMADO:SaveObject()"
"DEBUG" 1948 "2005-07-09 12:18:07.067" "Adding message to database. File: C:\Program Files\hMailServer\Data\{EE8A9995-24F4-4705-AA79-32763F2AD3B1}.eml"
"DEBUG" 1948 "2005-07-09 12:18: 07.077" "PMADO:~SaveObject()"
"DEBUG" 1948 "2005-07-09 12:18:07.077" "Messages::~Save()"
"SMTPD" 1948 "2005-07-09 12:18:07.077" " 192.168.1.2" "SENT: 221 goodbye"
"DEBUG" 1948 "2005-07-09 12:18:07.077" "SocketConnection::~SocketConnection()"
"TCPIP" 1948 "2005-07-09 12:18:07.077" "SMTPD - Connection to client 192.168.1.2 closed."
"DEBUG" 1820 "2005-07-09 12:18:07.077" "PersistentMessage::ReadObject()"
"DEBUG" 1820 "2005-07-09 12:18:07.087" "PersistentMessage::~ReadObject()"
"DEBUG" 1980 "2005-07-09 12:18:07.087" "SD:DeliverMessage"
"APPLICATION" 1980 "2005-07-09 12:18:07.087" "SMTPDeliverer - Message 23: Delivering message from test@******.dyndns.org to ******@gmail.com."
"DEBUG" 1980 "2005-07-09 12:18:07.097" "SD:_DeliverToExternalAccounts"
"TCPIP" 1980 "2005-07-09 12:18: 07.097" "DNS - MX Lookup: gmail.com"
"TCPIP" 1980 "2005-07-09 12:18:07.107" "DNS - MX Result: 5 servers"
"DEBUG" 1980 "2005-07-09 12:18: 07.107" "SD:_InitiateExternalConnection"
"DEBUG" 1980 "2005-07-09 12:18:07.238" "SocketConnection::SocketConnection()"
"DEBUG" 1980 "2005-07-09 12:18:07.248 " "SocketConnection::~_SendData() - E2"
"DEBUG" 1980 "2005-07-09 12:18:07.378" "SMTPCC::_ParseASCII()"
"SMTPC" 1980 "2005-07-09 12:18:07.378" " 64.233.185.114" "RECEIVED: 220 mx.gmail.com ESMTP 15si2628886wrl"
"DEBUG" 1980 "2005-07-09 12:18:07.378" "SMTPCC:_SendData()"
"SMTPC" 1980 "2005-07-09 12:18: 07.378" "64.233.185.114" "SENT: HELO ******.dyndns.org"
"DEBUG" 1980 "2005-07-09 12:18:07.378" "SMTPCC:~_SendData()"
"DEBUG" 1980 "2005-07-09 12:18:07.378" "SMTPCC::~_ParseASCII() - E2"
"DEBUG" 1980 "2005-07-09 12:18:07.518" "SMTPCC::_ParseASCII()"
"SMTPC" 1980 "2005-07-09 12:18: 07.518" "64.233.185.114" "RECEIVED: 250 mx.gmail.com at your service"
"DEBUG" 1980 "2005-07-09 12:18:07.518" "SMTPCC:_SendData()"
"SMTPC" 1980 "2005-07-09 12:18:07.518" "64.233.185.114" "SENT: MAIL FROM:<test@******.dyndns.org>"
"DEBUG" 1980 "2005-07-09 12:18:07.518" "SMTPCC:~_SendData()"
"DEBUG" 1980 "2005-07-09 12:18:07.518" "SMTPCC::~_ParseASCII() - E6"
"DEBUG" 1980 "2005-07-09 12:18: 07.658" "SMTPCC::_ParseASCII()"
"SMTPC" 1980 "2005-07-09 12:18:07.658" "64.233.185.114" "RECEIVED: 250 2.1.0 OK"
"DEBUG" 1980 "2005-07-09 12:18: 07.658" "SMTPCC::~_ParseASCII() - E8"
"DEBUG" 1980 "2005-07-09 12:18:07.658" "SMTPCC:_SendData()"
"SMTPC" 1980 "2005-07-09 12:18:07.668" " 64.233.185.114" "SENT: RCPT TO:<******@gmail.com>"
"DEBUG" 1980 "2005-07-09 12:18:07.668" "SMTPCC:~_SendData()"
"DEBUG" 1980 "2005-07-09 12:18: 07.919" "SMTPCC::_ParseASCII()"
"SMTPC" 1980 "2005-07-09 12:18:07.919" "64.233.185.114" "RECEIVED: 250 2.1.5 OK"
"DEBUG" 1980 "2005-07-09 12:18: 07.919" "SMTPCC:_SendData()"
"SMTPC" 1980 "2005-07-09 12:18:07.919" "64.233.185.114" "SENT: DATA"
"DEBUG" 1980 "2005-07-09 12:18: 07.919" "SMTPCC:~_SendData()"
"DEBUG" 1980 "2005-07-09 12:18:07.919" "SMTPCC::~_ParseASCII() - E10"
"DEBUG" 1980 "2005-07-09 12:18:08.049" "SMTPCC::_ParseASCII()"
"SMTPC" 1980 "2005-07-09 12:18:08.049" "64.233.185.114" "RECEIVED: 354 Go ahead"
"DEBUG" 1980 "2005-07-09 12:18:08.049" "SocketConnection::SendFileContents()"
"DEBUG" 1980 "2005-07-09 12:18:08.059" "SocketConnection::SendFileContents() - E2"
"DEBUG" 1980 "2005-07-09 12:18:08.059" "SMTPCC:_SendData()"
"SMTPC" 1980 "2005-07-09 12:18: 08.059" "64.233.185.114" "SENT: [nl]."
"DEBUG" 1980 "2005-07-09 12:18:08.059" "SMTPCC:~_SendData()"
"DEBUG" 1980 "2005-07-09 12:18: 08.059" "SMTPCC::~_ParseASCII() - E11"
"DEBUG" 1980 "2005-07-09 12:18:08.870" "SMTPCC::_ParseASCII()"
"SMTPC" 1980 "2005-07-09 12:18:08.880" " 64.233.185.114" "RECEIVED: 250 2.0.0 OK 1120907889 15si2628886wrl"
"DEBUG" 1980 "2005-07-09 12:18:08.880" "SMTPCC:_SendData()"
"SMTPC" 1980 "2005-07-09 12:18: 08.880" "64.233.185.114" "SENT: QUIT"
"DEBUG" 1980 "2005-07-09 12:18:08.880" "SMTPCC:~_SendData()"
"DEBUG" 1980 "2005-07-09 12:18: 08.880" "SMTPCC::~_ParseASCII() - E12"
"DEBUG" 1980 "2005-07-09 12:18:08.880" "SD:~_InitiateExternalConnection-5"
"DEBUG" 1980 "2005-07-09 12:18:08.880" "SocketConnection::~SocketConnection()"
"DEBUG" 1980 "2005-07-09 12:18:08.880" "SD:~_DeliverToExternalAccounts-1"
"DEBUG" 1980 "2005-07-09 12:18:08.880" "SD:_CollectDeliveryResult"
"DEBUG" 1980 "2005-07-09 12:18: 08.880" "SD:~_CollectDeliveryResult"
"DEBUG" 1980 "2005-07-09 12:18:08.880" "PersistentMessage::DeleteObject()"
"DEBUG" 1980 "2005-07-09 12:18:08.880" "PersistentMessage::DeleteFile()"
"DEBUG" 1980 "2005-07-09 12:18:08.890" "PersistentMessage::~DeleteFile() - E3"
"DEBUG" 1980 "2005-07-09 12:18:08.890" "PersistentMessage::DeleteObject() - E5"
"APPLICATION" 1980 "2005-07-09 12:18:08.890" "SMTPDeliverer - Message 23: Message delivery complete."
"DEBUG" 1980 "2005-07-09 12:18:08.890" "SD:~DeliverMessage"

**********************************************Second message with correct password********************************************************
"TCPIP" 1988 "2005-07-09 12:20:16.473" "SMTPD - Connection from 192.168.1.2 accepted."
"DEBUG" 1992 "2005-07-09 12:20:16.473" "SocketConnection::SocketConnection()"
"SMTPD" 1992 "2005-07-09 12:20:16.473" "192.168.1.2" "SENT: 220 ******.dyndns.org ESMTP hMailServer 3.4.1-B86 "
"SMTPD" 1992 "2005-07-09 12:20:16.483" "192.168.1.2" "RECEIVED: EHLO [192.168.1.2]"
"SMTPD" 1992 "2005-07-09 12:20: 16.483" "192.168.1.2" "SENT: 250-hmailserver[nl]250 AUTH LOGIN"
"SMTPD" 1992 "2005-07-09 12:20:16.493" "192.168.1.2 " "RECEIVED: AUTH LOGIN"
"SMTPD" 1992 "2005-07-09 12:20:16.493" "192.168.1.2" "SENT: 334 VXNlcm5hbWU6"
"SMTPD" 1992 "2005-07-09 12:20: 16.493" "192.168.1.2" "RECEIVED: dGVzdEB1cmZtYWlsLmR5bmRucy5vcmc="
"SMTPD" 1992 "2005-07-09 12:20:16.493" " 192.168.1.2" "SENT: 334 UGFzc3dvcmQ6"
"SMTPD" 1992 "2005-07-09 12:20:16.493" "192.168.1.2" "RECEIVED: dGVzdA=="
"SMTPD" 1992 "2005-07-09 12:20: 16.503" "192.168.1.2" "SENT: 235 authenticated."
"SMTPD" 1992 "2005-07-09 12:20:16.503" "192.168.1.2" "RECEIVED: MAIL FROM: < test@******.dyndns.org>"
"SMTPD" 1992 "2005-07-09 12:20:16.503" "192.168.1.2" "SENT: 250 test@******.dyndns.org... Sender OK"
"SMTPD" 1992 "2005-07-09 12:20:16.513" "192.168.1.2" "RECEIVED: RCPT TO: < ******@gmail.com>"
"SMTPD" 1992 "2005-07-09 12:20:16.513" "192.168.1.2" "SENT: 250 OK its for ******@gmail.com "
"SMTPD" 1992 "2005-07-09 12:20:16.523" "192.168.1.2" "RECEIVED: DATA"
"SMTPD" 1992 "2005-07-09 12:20:16.523" " 192.168.1.2" "SENT: 354 ok send! end with <crlf>.<crlf>"
"DEBUG" 1992 "2005-07-09 12:20:16.654" "Message added. File: C:\Program Files\hMailServer\Data\{42F6BADD-7311-49AF-8139-64741B367562}.eml"
"SMTPD" 1992 "2005-07-09 12:20:16.654" "192.168.1.2" "SENT: 250 Message queued (0.131 seconds)"
"SMTPD" 1992 "2005-07-09 12:20: 16.654" "192.168.1.2" "RECEIVED: QUIT"
"DEBUG" 1992 "2005-07-09 12:20:16.664" "Messages::Save()"
"DEBUG" 1992 "2005-07-09 12:20: 16.664" "Messages::Save() - Message iteration."
"DEBUG" 1992 "2005-07-09 12:20:16.664" "PMADO:SaveObject()"
"DEBUG" 1992 "2005-07-09 12:20:16.664" "Adding message to database. File: C:\Program Files\hMailServer\Data\{42F6BADD-7311-49AF-8139-64741B367562}.eml"
"DEBUG" 1992 "2005-07-09 12:20:16.664" "PMADO:~SaveObject()"
"DEBUG" 1992 "2005-07-09 12:20:16.664" "Messages::~Save()"
"SMTPD" 1992 "2005-07-09 12:20: 16.664" "192.168.1.2" "SENT: 221 goodbye"
"DEBUG" 1992 "2005-07-09 12:20:16.674" "SocketConnection::~SocketConnection()"
"TCPIP" 1992 "2005-07-09 12:20: 16.674" "SMTPD - Connection to client 192.168.1.2 closed."
"DEBUG" 1820 "2005-07-09 12:20:16.674" "PersistentMessage::ReadObject()"
"DEBUG" 1820 "2005-07-09 12:20: 16.674" "PersistentMessage::~ReadObject()"
"DEBUG" 2000 "2005-07-09 12:20:16.684" "SD:DeliverMessage"
"APPLICATION" 2000 "2005-07-09 12:20:16.684" "SMTPDeliverer - Message 24: Delivering message from test@******.dyndns.org to ******@gmail.com."
"DEBUG" 2000 "2005-07-09 12:20:16.684" "SD:_DeliverToExternalAccounts"
"TCPIP" 2000 "2005-07-09 12:20:16.684" "DNS - MX Lookup: gmail.com"
"TCPIP" 2000 "2005-07-09 12:20:16.734" "DNS - MX Result: 5 servers"
"DEBUG" 2000 "2005-07-09 12:20:16.734" "SD:_InitiateExternalConnection"
"DEBUG" 2000 "2005-07-09 12:20:16.894" "SocketConnection::SocketConnection()"
"DEBUG" 2000 "2005-07-09 12:20: 16.894" "SocketConnection::~_SendData() - E2"
"DEBUG" 2000 "2005-07-09 12:20:17.034" "SMTPCC::_ParseASCII()"
"SMTPC" 2000 "2005-07-09 12:20:17.034" " 64.233.185.114" "RECEIVED: 220 mx.gmail.com ESMTP 26si880771wrl"
"DEBUG" 2000 "2005-07-09 12:20:17.034" "SMTPCC:_SendData()"
"SMTPC" 2000 "2005-07-09 12:20:17.034" "64.233.185.114" "SENT: HELO ******.dyndns.org"
"DEBUG" 2000 "2005-07-09 12:20: 17.034" "SMTPCC:~_SendData()"
"DEBUG" 2000 "2005-07-09 12:20:17.034" "SMTPCC::~_ParseASCII() - E2"
"DEBUG" 2000 "2005-07-09 12:20:17.264" "SMTPCC::_ParseASCII()"
"SMTPC" 2000 "2005-07-09 12:20:17.264" "64.233.185.114" "RECEIVED: 250 mx.gmail.com at your service"
"DEBUG" 2000 "2005-07-09 12:20: 17.275" "SMTPCC:_SendData()"
"SMTPC" 2000 "2005-07-09 12:20:17.275" "64.233.185.114" "SENT: MAIL FROM:< test@******.dyndns.org>"
"DEBUG" 2000 "2005-07-09 12:20:17.275" "SMTPCC:~_SendData()"
"DEBUG" 2000 "2005-07-09 12:20:17.275" "SMTPCC::~_ParseASCII() - E6"
"DEBUG" 2000 "2005-07-09 12:20:17.475" "SMTPCC::_ParseASCII()"
"SMTPC" 2000 "2005-07-09 12:20:17.475" "64.233.185.114" "RECEIVED: 250 2.1.0 OK"
"DEBUG" 2000 "2005-07-09 12:20:17.475" "SMTPCC::~_ParseASCII() - E8"
"DEBUG" 2000 "2005-07-09 12:20:17.475" "SMTPCC:_SendData()"
"SMTPC" 2000 "2005-07-09 12:20: 17.475" "64.233.185.114" "SENT: RCPT TO:<******@gmail.com>"
"DEBUG" 2000 "2005-07-09 12:20:17.475 " "SMTPCC:~_SendData()"
"DEBUG" 2000 "2005-07-09 12:20:17.665" "SMTPCC::_ParseASCII()"
"SMTPC" 2000 "2005-07-09 12:20:17.665" " 64.233.185.114" "RECEIVED: 250 2.1.5 OK"
"DEBUG" 2000 "2005-07-09 12:20:17.665" "SMTPCC:_SendData()"
"SMTPC" 2000 "2005-07-09 12:20:17.665" " 64.233.185.114" "SENT: DATA"
"DEBUG" 2000 "2005-07-09 12:20:17.665" "SMTPCC:~_SendData()"
"DEBUG" 2000 "2005-07-09 12:20: 17.665" "SMTPCC::~_ParseASCII() - E10"
"DEBUG" 2000 "2005-07-09 12:20:17.805" "SMTPCC::_ParseASCII()"
"SMTPC" 2000 "2005-07-09 12:20:17.805" " 64.233.185.114" "RECEIVED: 354 Go ahead"
"DEBUG" 2000 "2005-07-09 12:20:17.805" "SocketConnection::SendFileContents()"
"DEBUG" 2000 "2005-07-09 12:20:17.805 " "SocketConnection::SendFileContents() - E2"
"DEBUG" 2000 "2005-07-09 12:20:17.805" "SMTPCC:_SendData()"
"SMTPC" 2000 "2005-07-09 12:20:17.805" " 64.233.185.114" "SENT: [nl]."
"DEBUG" 2000 "2005-07-09 12:20:17.805" "SMTPCC:~_SendData()"
"DEBUG" 2000 "2005-07-09 12:20: 17.805" "SMTPCC::~_ParseASCII() - E11"
"DEBUG" 2000 "2005-07-09 12:20:18.677" "SMTPCC::_ParseASCII()"
"SMTPC" 2000 "2005-07-09 12:20:18.677" " 64.233.185.114" "RECEIVED: 250 2.0.0 OK 1120908019 26si880771wrl"
"DEBUG" 2000 "2005-07-09 12:20:18.677" "SMTPCC:_SendData()"
"SMTPC" 2000 "2005-07-09 12:20: 18.677" "64.233.185.114" "SENT: QUIT"
"DEBUG" 2000 "2005-07-09 12:20:18.677" "SMTPCC:~_SendData()"
"DEBUG" 2000 "2005-07-09 12:20: 18.677" "SMTPCC::~_ParseASCII() - E12"
"DEBUG" 2000 "2005-07-09 12:20:18.677" "SD:~_InitiateExternalConnection-5"
"DEBUG" 2000 "2005-07-09 12:20:18.677" "SocketConnection::~SocketConnection()"
"DEBUG" 2000 "2005-07-09 12:20:18.677" "SD:~_DeliverToExternalAccounts-1"
"DEBUG" 2000 "2005-07-09 12:20:18.677" "SD:_CollectDeliveryResult"
"DEBUG" 2000 "2005-07-09 12:20: 18.677" "SD:~_CollectDeliveryResult"
"DEBUG" 2000 "2005-07-09 12:20:18.677" "PersistentMessage::DeleteObject()"
"DEBUG" 2000 "2005-07-09 12:20:18.687" "PersistentMessage::DeleteFile()"
"DEBUG" 2000 "2005-07-09 12:20:18.687" "PersistentMessage::~DeleteFile() - E3"
"DEBUG" 2000 "2005-07-09 12:20:18.687" "PersistentMessage::DeleteObject() - E5"
"APPLICATION" 2000 "2005-07-09 12:20:18.687" "SMTPDeliverer - Message 24: Message delivery complete."
"DEBUG" 2000 "2005-07-09 12:20:18.687" "SD:~DeliverMessage"

version: hMailServer 3.4.1 - Build 86 (9786) - 2005-04-10

internal MqSql DB

Post Reply