
ssl/tls and starttls [50%]
Re: ssl/tls and starttls [50%]
I also need outbound to be able to relay via Office365
(Sadly the only allowed smtp on the firewall).

Re: ssl/tls and starttls [50%]
Bills experimental build supports STARTTLS for incoming SMTP. Still nothing more. But works very well for me.
I'm waiting also for further enhancements regarding STARTTLS for outgoing SMTP. Some people in this forum need it e.g. for ISPs smarthosts. As far as I know they use "stunnel" for workaround...
Feel free to vote here what you need next:
http://www.hmailserver.com/forum/viewtopic.php?t=26118
http://www.hmailserver.com/forum/viewtopic.php?t=25966
I'm waiting also for further enhancements regarding STARTTLS for outgoing SMTP. Some people in this forum need it e.g. for ISPs smarthosts. As far as I know they use "stunnel" for workaround...
Feel free to vote here what you need next:
http://www.hmailserver.com/forum/viewtopic.php?t=26118
http://www.hmailserver.com/forum/viewtopic.php?t=25966
Last edited by prisma on 2014-06-02 15:43, edited 1 time in total.
Re: ssl/tls and starttls [50%]
A few weeks ago I added outbound STARTTLS to a test build here just for routes but does not work. Always gives handshake errors. I suspect it's an openssl related issue but been unable to debug it. I'll share the build if someone wants to test but realize it'd require advanced low-level testing. Like wireshark or such and significant knowledge of SSL/TLS to help figure out why handshake is failing before it'd be useful.
Bill
Bill
hMailServer build LIVE on my servers: 5.4-B2014050402
#hmailserver on FreeNode IRC https://webchat.freenode.net/?channels=#hmailserver
*** ABSENT FROM hMail! Those in IRC know how to find me if urgent. ***
#hmailserver on FreeNode IRC https://webchat.freenode.net/?channels=#hmailserver
*** ABSENT FROM hMail! Those in IRC know how to find me if urgent. ***
Re: ssl/tls and starttls [50%]
Oh, didn't recognize this, share it with me!Bill48105 wrote:A few weeks ago I added outbound STARTTLS to a test build here just for routes but does not work. Always gives handshake errors. I suspect it's an openssl related issue but been unable to debug it. I'll share the build if someone wants to test but realize it'd require advanced low-level testing. Like wireshark or such and significant knowledge of SSL/TLS to help figure out why handshake is failing before it'd be useful.
Bill
Re: ssl/tls and starttls [50%]
Yeah I mentioned it in another post but didn't post up since it didn't work. It's possible it just requires tweeking ciphers (glad I added the INI) or something trivial I'm overlooking. I'll send you PMprisma wrote:Oh, didn't recognize this, share it with me!Bill48105 wrote:A few weeks ago I added outbound STARTTLS to a test build here just for routes but does not work. Always gives handshake errors. I suspect it's an openssl related issue but been unable to debug it. I'll share the build if someone wants to test but realize it'd require advanced low-level testing. Like wireshark or such and significant knowledge of SSL/TLS to help figure out why handshake is failing before it'd be useful.
Bill
thx
Bill
hMailServer build LIVE on my servers: 5.4-B2014050402
#hmailserver on FreeNode IRC https://webchat.freenode.net/?channels=#hmailserver
*** ABSENT FROM hMail! Those in IRC know how to find me if urgent. ***
#hmailserver on FreeNode IRC https://webchat.freenode.net/?channels=#hmailserver
*** ABSENT FROM hMail! Those in IRC know how to find me if urgent. ***
Re: ssl/tls and starttls [50%]
I am happy to do some testing too.. send me the info 

Re: ssl/tls and starttls [50%]
I can't send you a pm directly Bill as I've not posted enough yet.
As far as I can see the test build sends STARTTLS and then further "in the clear" data... compared to Outlook.
As far as I can see the test build sends STARTTLS and then further "in the clear" data... compared to Outlook.
Re: ssl/tls and starttls [50%]
Thx drsox. I'll need to check if the build I shared. If you set hmailserver.ini [Settings] LogLevel=99 you will get more low level info including that hmail attempts the handshake & the errors when it does. That snippet you posted makes it look like it ever tries but that can't be the case based on what i've seen here.drsox wrote:I can't send you a pm directly Bill as I've not posted enough yet.
As far as I can see the test build sends STARTTLS and then further "in the clear" data... compared to Outlook.
Something like this when sending to gmail:
Code: Select all
"APPLICATION" 3504 "2014-05-21 22:58:27.661" "SMTPDeliverer - Message 1596: Relaying to host smtp.gmail.com."
"DEBUG" 3504 "2014-05-21 22:58:27.661" "SD::_InitiateExternalConnection"
"DEBUG" 3504 "2014-05-21 22:58:27.661" "TCPConnection::PrepareSSLContext - SSLOptionList Option: default_workarounds,no_sslv2"
"DEBUG" 3504 "2014-05-21 22:58:27.661" "TCPConnection::PrepareSSLContext - SSLCipherList Option not set, skipping."
"DEBUG" 3504 "2014-05-21 22:58:27.661" "TCPConnection::PrepareSSLContext - Found SSL Option: default_workarounds"
"DEBUG" 3504 "2014-05-21 22:58:27.661" "TCPConnection::PrepareSSLContext - SSL Option SET: default_workarounds"
"DEBUG" 3504 "2014-05-21 22:58:27.661" "TCPConnection::PrepareSSLContext - Found SSL Option: no_sslv2"
"DEBUG" 3504 "2014-05-21 22:58:27.661" "TCPConnection::PrepareSSLContext - SSL Option SET: no_sslv2"
"DEBUG" 3504 "2014-05-21 22:58:27.661" "TCPConnection::Start"
"DEBUG" 3504 "2014-05-21 22:58:27.661" "Creating session 5"
"DEBUG" 3504 "2014-05-21 22:58:27.661" "TCPConnection::Try"
"DEBUG" 3504 "2014-05-21 22:58:27.661" "TCPConnection::usessl"
"DEBUG" 3504 "2014-05-21 22:58:27.661" "TCPCconnection::GetSocket(): next_layer()"
"DEBUG" 3504 "2014-05-21 22:58:27.661" "TCPConnection::SocketisNOTopen"
"TCPIP" 3504 "2014-05-21 22:58:27.661" "Connecting to smtp.gmail.com..."
"SMTPD" 1448 4 "2014-05-21 22:58:27.661" "192.168.3.20" "RECEIVED: QUIT"
"SMTPD" 1448 4 "2014-05-21 22:58:27.661" "192.168.3.20" "SENT: 221 goodbye"
"DEBUG" 1448 "2014-05-21 22:58:27.661" "TCPConnection::Write non ssl"
"DEBUG" 3200 "2014-05-21 22:58:27.661" "Closing TCP/IP socket"
"DEBUG" 3200 "2014-05-21 22:58:27.661" "Ending session 4"
"DEBUG" 3200 "2014-05-21 22:58:27.739" "TCPCconnection::GetSocket(): next_layer()"
"DEBUG" 3200 "2014-05-21 22:58:27.770" "TCPConnection::~TCPConnection 4USESSL & TLS1"
"DEBUG" 3200 "2014-05-21 22:58:27.770" "TCPConnection::Read next_layer()"
"DEBUG" 3200 "2014-05-21 22:58:27.801" "SMTPClientConnection::_ParseASCII()"
"DEBUG" 3200 "2014-05-21 22:58:27.801" "TCPCconnection::GetSocket(): next_layer()"
"SMTPC" 3200 5 "2014-05-21 22:58:27.801" "74.125.193.109" "RECEIVED: 220 mx.google.com ESMTP v8sm9936510igk.16 - gsmtp"
"DEBUG" 3200 "2014-05-21 22:58:27.801" "TCPCconnection::GetSocket(): next_layer()"
"SMTPC" 3200 5 "2014-05-21 22:58:27.801" "74.125.193.109" "SENT: EHLO WIN7-20"
"DEBUG" 3200 "2014-05-21 22:58:27.801" "TCPConnection::Write next_layer()"
"DEBUG" 3200 "2014-05-21 22:58:27.801" "SMTPClientConnection::~_ParseASCII() - 2"
"DEBUG" 1448 "2014-05-21 22:58:27.801" "TCPConnection::Read next_layer()"
"DEBUG" 3428 "2014-05-21 22:58:27.926" "SMTPClientConnection::_ParseASCII()"
"DEBUG" 3428 "2014-05-21 22:58:27.926" "TCPCconnection::GetSocket(): next_layer()"
"SMTPC" 3428 5 "2014-05-21 22:58:27.926" "74.125.193.109" "RECEIVED: 250-mx.google.com at your service, [*.*.*.*]"
"DEBUG" 3428 "2014-05-21 22:58:27.926" "SMTPClientConnection::~_ParseASCII() - 1"
"DEBUG" 3428 "2014-05-21 22:58:27.926" "TCPConnection::Read next_layer()"
"DEBUG" 3200 "2014-05-21 22:58:27.926" "SMTPClientConnection::_ParseASCII()"
"DEBUG" 3200 "2014-05-21 22:58:27.926" "TCPCconnection::GetSocket(): next_layer()"
"SMTPC" 3200 5 "2014-05-21 22:58:27.926" "74.125.193.109" "RECEIVED: 250-SIZE 35882577"
"DEBUG" 3200 "2014-05-21 22:58:27.926" "SMTPClientConnection::~_ParseASCII() - 1"
"DEBUG" 3200 "2014-05-21 22:58:27.926" "TCPConnection::Read next_layer()"
"DEBUG" 3428 "2014-05-21 22:58:27.926" "SMTPClientConnection::_ParseASCII()"
"DEBUG" 3428 "2014-05-21 22:58:27.926" "TCPCconnection::GetSocket(): next_layer()"
"SMTPC" 3428 5 "2014-05-21 22:58:27.926" "74.125.193.109" "RECEIVED: 250-8BITMIME"
"DEBUG" 3428 "2014-05-21 22:58:27.926" "SMTPClientConnection::~_ParseASCII() - 1"
"DEBUG" 3428 "2014-05-21 22:58:27.926" "TCPConnection::Read next_layer()"
"DEBUG" 3200 "2014-05-21 22:58:27.926" "SMTPClientConnection::_ParseASCII()"
"DEBUG" 3200 "2014-05-21 22:58:27.926" "TCPCconnection::GetSocket(): next_layer()"
"SMTPC" 3200 5 "2014-05-21 22:58:27.926" "74.125.193.109" "RECEIVED: 250-STARTTLS"
"DEBUG" 3200 "2014-05-21 22:58:27.926" "SMTPClientConnection::~_ParseASCII() - 1"
"DEBUG" 3200 "2014-05-21 22:58:27.926" "TCPConnection::Read next_layer()"
"DEBUG" 3428 "2014-05-21 22:58:27.926" "SMTPClientConnection::_ParseASCII()"
"DEBUG" 3428 "2014-05-21 22:58:27.926" "TCPCconnection::GetSocket(): next_layer()"
"SMTPC" 3428 5 "2014-05-21 22:58:27.926" "74.125.193.109" "RECEIVED: 250-ENHANCEDSTATUSCODES"
"DEBUG" 3428 "2014-05-21 22:58:27.926" "SMTPClientConnection::~_ParseASCII() - 1"
"DEBUG" 3428 "2014-05-21 22:58:27.926" "TCPConnection::Read next_layer()"
"DEBUG" 3200 "2014-05-21 22:58:27.926" "SMTPClientConnection::_ParseASCII()"
"DEBUG" 3200 "2014-05-21 22:58:27.926" "TCPCconnection::GetSocket(): next_layer()"
"SMTPC" 3200 5 "2014-05-21 22:58:27.926" "74.125.193.109" "RECEIVED: 250 CHUNKING"
"DEBUG" 3200 "2014-05-21 22:58:27.926" "TCPCconnection::GetSocket(): next_layer()"
"SMTPC" 3200 5 "2014-05-21 22:58:27.926" "74.125.193.109" "SENT: STARTTLS"
"DEBUG" 3200 "2014-05-21 22:58:27.926" "TCPConnection::Write next_layer()"
"DEBUG" 3200 "2014-05-21 22:58:27.926" "TCPConnection::STARTTLS_Handshake handshake1"
"DEBUG" 3200 "2014-05-21 22:58:27.926" "TCPConnection::STARTTLS_Handshake handshake3"
"DEBUG" 3200 "2014-05-21 22:58:27.926" "STARTTLS true"
"DEBUG" 3200 "2014-05-21 22:58:27.926" "sleeping 2 sec"
"DEBUG" 964 "2014-05-21 22:58:27.957" "TCPCconnection::GetSocket(): next_layer()"
"TCPIP" 964 "2014-05-21 22:58:27.957" "TCPConnection - SSL handshake with client failed. Error code: 336031996, Message: unknown protocol, Remote IP: 74.125.193.109"
"DEBUG" 3200 "2014-05-21 22:58:29.939" "_stateSTARTTLS = 3"
"DEBUG" 3200 "2014-05-21 22:58:29.939" "StartTLSState3() true"
"DEBUG" 3200 "2014-05-21 22:58:29.939" "TCPCconnection::GetSocket(): lowest_layer()"
"SMTPC" 3200 5 "2014-05-21 22:58:29.939" "74.125.193.109" "SENT: EHLO WIN7-20"
"DEBUG" 3428 "2014-05-21 22:58:29.939" "TCPConnection::Write ssl"
"DEBUG" 3200 "2014-05-21 22:58:29.939" "TCPCconnection::GetSocket(): lowest_layer()"
"DEBUG" 3200 "2014-05-21 22:58:29.939" "The write operation failed. Remote IP: 74.125.193.109, Session: 5, Code: 336031996, Message: unknown protocol"
"DEBUG" 3504 "2014-05-21 22:58:29.939" "SD::~_InitiateExternalConnection-5"
"DEBUG" 3504 "2014-05-21 22:58:29.939" "Ending session 5"
"DEBUG" 3504 "2014-05-21 22:58:29.939" "SD::~_DeliverToExternalAccounts-2"
"DEBUG" 3504 "2014-05-21 22:58:29.939" "Collect delivery result"
"DEBUG" 3504 "2014-05-21 22:58:29.939" "Collect delivery result - Done"
"DEBUG" 3504 "2014-05-21 22:58:29.939" "SD::_RescheduleDelivery"
"DEBUG" 3504 "2014-05-21 22:58:29.939" "Retrieving retry options."
"DEBUG" 3504 "2014-05-21 22:58:29.939" "Starting rescheduling."
"APPLICATION" 3504 "2014-05-21 22:58:29.939" "SMTPDeliverer - Message 1596: Message could not be delivered. Scheduling it for later delivery in 60 minutes."
"DEBUG" 3504 "2014-05-21 22:58:29.939" "PersistentMessage::SetNextTryTime()"
"DEBUG" 3504 "2014-05-21 22:58:29.939" "PersistentMessage::~SetNextTryTime()"
"DEBUG" 3504 "2014-05-21 22:58:29.939" "Message rescheduled for later delivery."
"APPLICATION" 3504 "2014-05-21 22:58:29.939" "SMTPDeliverer - Message 1596: Message delivery thread completed."
"DEBUG" 3416 "2014-05-21 22:58:57.551" "Deleting message"
"DEBUG" 3416 "2014-05-21 22:58:57.551" "Deleting message file."
And PS. the 2nd EHLO is being sent blindly for now. Obviously it should be based on results of the handshake but at this point was just trying to get past the handshake.
hMailServer build LIVE on my servers: 5.4-B2014050402
#hmailserver on FreeNode IRC https://webchat.freenode.net/?channels=#hmailserver
*** ABSENT FROM hMail! Those in IRC know how to find me if urgent. ***
#hmailserver on FreeNode IRC https://webchat.freenode.net/?channels=#hmailserver
*** ABSENT FROM hMail! Those in IRC know how to find me if urgent. ***
Re: ssl/tls and starttls [50%]
From my transaction: (Might contain the end of my smtp local delivery session too)
Code: Select all
"DEBUG" 2708 "2014-06-02 21:43:21.092" "Performing local delivery"
"DEBUG" 2708 "2014-06-02 21:43:21.095" "Local delivery completed"
"DEBUG" 2708 "2014-06-02 21:43:21.097" "Performing external delivery"
"APPLICATION" 2708 "2014-06-02 21:43:21.100" "SMTPDeliverer - Message 3: Relaying to host outlook.office365.com."
"DEBUG" 2708 "2014-06-02 21:43:21.101" "SD::_InitiateExternalConnection"
"DEBUG" 2708 "2014-06-02 21:43:21.102" "TCPConnection::Start"
"DEBUG" 2708 "2014-06-02 21:43:21.103" "Creating session 3"
"DEBUG" 2708 "2014-06-02 21:43:21.104" "TCPConnection::Try"
"DEBUG" 10564 "2014-06-02 21:43:21.277" "TCPConnection::~TCPConnection 6!USESSL & !TLS"
"DEBUG" 10564 "2014-06-02 21:43:21.278" "TCPConnection::Read non ssl"
"DEBUG" 7768 "2014-06-02 21:43:21.418" "SMTPClientConnection::_ParseASCII()"
"SMTPC" 7768 3 "2014-06-02 21:43:21.418" "132.245.81.178" "RECEIVED: 220 BY2PR06CA042.outlook.office365.com Microsoft ESMTP MAIL Service ready at Mon, 2 Jun 2014 20:43:24 +0000"
"SMTPC" 7768 3 "2014-06-02 21:43:21.419" "132.245.81.178" "SENT: EHLO HORSE"
"DEBUG" 7768 "2014-06-02 21:43:21.419" "TCPConnection::Write non ssl"
"DEBUG" 7768 "2014-06-02 21:43:21.420" "SMTPClientConnection::~_ParseASCII() - 2"
"DEBUG" 6764 "2014-06-02 21:43:21.421" "TCPConnection::Read non ssl"
"DEBUG" 19348 "2014-06-02 21:43:21.569" "SMTPClientConnection::_ParseASCII()"
"SMTPC" 19348 3 "2014-06-02 21:43:21.570" "132.245.81.178" "RECEIVED: 250-BY2PR06CA042.outlook.office365.com Hello [86.130.98.117]"
"DEBUG" 19348 "2014-06-02 21:43:21.571" "SMTPClientConnection::~_ParseASCII() - 1"
"DEBUG" 19348 "2014-06-02 21:43:21.571" "TCPConnection::Read non ssl"
"DEBUG" 17040 "2014-06-02 21:43:21.572" "SMTPClientConnection::_ParseASCII()"
"SMTPC" 17040 3 "2014-06-02 21:43:21.573" "132.245.81.178" "RECEIVED: 250-SIZE 78643200"
"DEBUG" 17040 "2014-06-02 21:43:21.573" "SMTPClientConnection::~_ParseASCII() - 1"
"DEBUG" 17040 "2014-06-02 21:43:21.574" "TCPConnection::Read non ssl"
"DEBUG" 19348 "2014-06-02 21:43:21.574" "SMTPClientConnection::_ParseASCII()"
"SMTPC" 19348 3 "2014-06-02 21:43:21.575" "132.245.81.178" "RECEIVED: 250-PIPELINING"
"DEBUG" 19348 "2014-06-02 21:43:21.575" "SMTPClientConnection::~_ParseASCII() - 1"
"DEBUG" 19348 "2014-06-02 21:43:21.576" "TCPConnection::Read non ssl"
"DEBUG" 6764 "2014-06-02 21:43:21.577" "SMTPClientConnection::_ParseASCII()"
"SMTPC" 6764 3 "2014-06-02 21:43:21.577" "132.245.81.178" "RECEIVED: 250-DSN"
"DEBUG" 6764 "2014-06-02 21:43:21.578" "SMTPClientConnection::~_ParseASCII() - 1"
"DEBUG" 6764 "2014-06-02 21:43:21.578" "TCPConnection::Read non ssl"
"DEBUG" 19348 "2014-06-02 21:43:21.579" "SMTPClientConnection::_ParseASCII()"
"SMTPC" 19348 3 "2014-06-02 21:43:21.580" "132.245.81.178" "RECEIVED: 250-ENHANCEDSTATUSCODES"
"DEBUG" 19348 "2014-06-02 21:43:21.580" "SMTPClientConnection::~_ParseASCII() - 1"
"DEBUG" 19348 "2014-06-02 21:43:21.581" "TCPConnection::Read non ssl"
"DEBUG" 17040 "2014-06-02 21:43:21.582" "SMTPClientConnection::_ParseASCII()"
"SMTPC" 17040 3 "2014-06-02 21:43:21.583" "132.245.81.178" "RECEIVED: 250-STARTTLS"
"DEBUG" 17040 "2014-06-02 21:43:21.584" "SMTPClientConnection::~_ParseASCII() - 1"
"DEBUG" 17040 "2014-06-02 21:43:21.585" "TCPConnection::Read non ssl"
"DEBUG" 19348 "2014-06-02 21:43:21.586" "SMTPClientConnection::_ParseASCII()"
"SMTPC" 19348 3 "2014-06-02 21:43:21.586" "132.245.81.178" "RECEIVED: 250-8BITMIME"
"DEBUG" 19348 "2014-06-02 21:43:21.587" "SMTPClientConnection::~_ParseASCII() - 1"
"DEBUG" 19348 "2014-06-02 21:43:21.588" "TCPConnection::Read non ssl"
"DEBUG" 17040 "2014-06-02 21:43:21.588" "SMTPClientConnection::_ParseASCII()"
"SMTPC" 17040 3 "2014-06-02 21:43:21.589" "132.245.81.178" "RECEIVED: 250-BINARYMIME"
"DEBUG" 17040 "2014-06-02 21:43:21.589" "SMTPClientConnection::~_ParseASCII() - 1"
"DEBUG" 17040 "2014-06-02 21:43:21.590" "TCPConnection::Read non ssl"
"DEBUG" 9088 "2014-06-02 21:43:21.591" "SMTPClientConnection::_ParseASCII()"
"SMTPC" 9088 3 "2014-06-02 21:43:21.591" "132.245.81.178" "RECEIVED: 250 CHUNKING"
"SMTPC" 9088 3 "2014-06-02 21:43:21.592" "132.245.81.178" "SENT: STARTTLS"
"DEBUG" 9088 "2014-06-02 21:43:21.592" "TCPConnection::Write non ssl"
"DEBUG" 9088 "2014-06-02 21:43:21.593" "TCPConnection::STARTTLS_Handshake handshake1"
"DEBUG" 9088 "2014-06-02 21:43:21.594" "TCPConnection::STARTTLS_Handshake handshake3"
"DEBUG" 9088 "2014-06-02 21:43:21.594" "STARTTLS true"
"DEBUG" 9088 "2014-06-02 21:43:21.595" "sleeping 2 sec"
"DEBUG" 15280 "2014-06-02 21:43:21.908" "TCPConnection::Read non ssl"
"DEBUG" 6764 "2014-06-02 21:43:22.593" "TCPConnection::Write non ssl"
"DEBUG" 7768 "2014-06-02 21:43:22.594" "Closing TCP/IP socket"
"DEBUG" 7768 "2014-06-02 21:43:22.596" "Ending session 2"
"DEBUG" 9088 "2014-06-02 21:43:23.596" "_stateSTARTTLS = 3"
"DEBUG" 9088 "2014-06-02 21:43:23.596" "StartTLSState3() true"
"SMTPC" 9088 3 "2014-06-02 21:43:23.597" "132.245.81.178" "SENT: EHLO HORSE"
"DEBUG" 17040 "2014-06-02 21:43:23.598" "TCPConnection::Write non ssl"
"DEBUG" 9088 "2014-06-02 21:43:23.599" "TCPConnection::Read non ssl"
"DEBUG" 7768 "2014-06-02 21:43:23.600" "SMTPClientConnection::_ParseASCII()"
"SMTPC" 7768 3 "2014-06-02 21:43:23.600" "132.245.81.178" "RECEIVED: 220 2.0.0 SMTP server ready"
"SMTPC" 7768 3 "2014-06-02 21:43:23.601" "132.245.81.178" "SENT: MAIL FROM:<testsender@heh.info>"
"DEBUG" 7768 "2014-06-02 21:43:23.602" "TCPConnection::Write non ssl"
"DEBUG" 7768 "2014-06-02 21:43:23.604" "SMTPClientConnection::~_ParseASCII() - 4"
"DEBUG" 9088 "2014-06-02 21:43:23.605" "TCPConnection::Read non ssl"
Re: ssl/tls and starttls [50%]
Very strange drsox. Not only do your logs never show "ssl" vs "non ssl" they don't show the handshake failing or completing either. And I don't see any of the next_layer first_layer lines either. Maybe your LogLevel setting is too low. I'll need to do some more testing here maybe try a relay to office365.
thx
Bill
thx
Bill
hMailServer build LIVE on my servers: 5.4-B2014050402
#hmailserver on FreeNode IRC https://webchat.freenode.net/?channels=#hmailserver
*** ABSENT FROM hMail! Those in IRC know how to find me if urgent. ***
#hmailserver on FreeNode IRC https://webchat.freenode.net/?channels=#hmailserver
*** ABSENT FROM hMail! Those in IRC know how to find me if urgent. ***
Re: ssl/tls and starttls [50%]
Oh.. Let me guess. Do you have SSL checked on the route page? That has to be checked. 

hMailServer build LIVE on my servers: 5.4-B2014050402
#hmailserver on FreeNode IRC https://webchat.freenode.net/?channels=#hmailserver
*** ABSENT FROM hMail! Those in IRC know how to find me if urgent. ***
#hmailserver on FreeNode IRC https://webchat.freenode.net/?channels=#hmailserver
*** ABSENT FROM hMail! Those in IRC know how to find me if urgent. ***
Re: ssl/tls and starttls [50%]
Oh, :\ sorry.. I assumed the SSL tick box would have enabled full socket SSL rather than TLS (are those the correct terms?).
Will tick the option and re-test
Sorry!
Will tick the option and re-test

Re: ssl/tls and starttls [50%]
Wireshark attached below. Looks like the server says hi and then hmailserver ends the connection?
Code: Select all
"DEBUG" 6224 "2014-06-02 22:15:30.408" "PersistentMessage::SetNextTryTime()"
"DEBUG" 6224 "2014-06-02 22:15:30.410" "PersistentMessage::~SetNextTryTime()"
"DEBUG" 9768 "2014-06-02 22:15:30.420" "Delivering message..."
"APPLICATION" 9768 "2014-06-02 22:15:30.421" "SMTPDeliverer - Message 3: Delivering message from testsender@x.info to testrcpt@x.info. File: C:\Program Files (x86)\hMailServer\Data\{E3A297F9-B7FD-4343-8EA1-879D708C3E6E}.eml"
"DEBUG" 9768 "2014-06-02 22:15:30.421" "Applying rules"
"DEBUG" 9768 "2014-06-02 22:15:30.422" "Performing local delivery"
"DEBUG" 9768 "2014-06-02 22:15:30.423" "Local delivery completed"
"DEBUG" 9768 "2014-06-02 22:15:30.423" "Performing external delivery"
"APPLICATION" 9768 "2014-06-02 22:15:30.424" "SMTPDeliverer - Message 3: Relaying to host outlook.office365.com."
"DEBUG" 9768 "2014-06-02 22:15:30.424" "SD::_InitiateExternalConnection"
"DEBUG" 9768 "2014-06-02 22:15:30.425" "TCPConnection::PrepareSSLContext - SSLOptionList Option: default_workarounds,no_sslv2"
"DEBUG" 9768 "2014-06-02 22:15:30.426" "TCPConnection::PrepareSSLContext - SSLCipherList Option not set, skipping."
"DEBUG" 9768 "2014-06-02 22:15:30.427" "TCPConnection::PrepareSSLContext - Found SSL Option: default_workarounds"
"DEBUG" 9768 "2014-06-02 22:15:30.427" "TCPConnection::PrepareSSLContext - SSL Option SET: default_workarounds"
"DEBUG" 9768 "2014-06-02 22:15:30.428" "TCPConnection::PrepareSSLContext - Found SSL Option: no_sslv2"
"DEBUG" 9768 "2014-06-02 22:15:30.428" "TCPConnection::PrepareSSLContext - SSL Option SET: no_sslv2"
"DEBUG" 9768 "2014-06-02 22:15:30.429" "TCPConnection::Start"
"DEBUG" 9768 "2014-06-02 22:15:30.430" "Creating session 5"
"DEBUG" 9768 "2014-06-02 22:15:30.431" "TCPConnection::Try"
"DEBUG" 9768 "2014-06-02 22:15:30.431" "TCPConnection::usessl"
"DEBUG" 9768 "2014-06-02 22:15:30.432" "TCPCconnection::GetSocket(): next_layer()"
"DEBUG" 9768 "2014-06-02 22:15:30.432" "TCPConnection::SocketisNOTopen"
"DEBUG" 9088 "2014-06-02 22:15:30.436" "TCPCconnection::GetSocket(): next_layer()"
"DEBUG" 9088 "2014-06-02 22:15:30.469" "TCPConnection::~TCPConnection 4USESSL & TLS1"
"DEBUG" 9088 "2014-06-02 22:15:30.469" "TCPConnection::Read next_layer()"
"DEBUG" 9088 "2014-06-02 22:15:30.480" "SMTPClientConnection::_ParseASCII()"
"DEBUG" 9088 "2014-06-02 22:15:30.481" "TCPCconnection::GetSocket(): next_layer()"
"SMTPC" 9088 5 "2014-06-02 22:15:30.482" "132.245.225.98" "RECEIVED: 220 DB4PR02CA0035.outlook.office365.com Microsoft ESMTP MAIL Service ready at Mon, 2 Jun 2014 21:15:32 +0000"
"DEBUG" 9088 "2014-06-02 22:15:30.482" "TCPCconnection::GetSocket(): next_layer()"
"SMTPC" 9088 5 "2014-06-02 22:15:30.483" "132.245.225.98" "SENT: EHLO HORSE"
"DEBUG" 9088 "2014-06-02 22:15:30.483" "TCPConnection::Write next_layer()"
"DEBUG" 9088 "2014-06-02 22:15:30.484" "SMTPClientConnection::~_ParseASCII() - 2"
"DEBUG" 5836 "2014-06-02 22:15:30.485" "TCPConnection::Read next_layer()"
"DEBUG" 5836 "2014-06-02 22:15:30.505" "SMTPClientConnection::_ParseASCII()"
"DEBUG" 5836 "2014-06-02 22:15:30.506" "TCPCconnection::GetSocket(): next_layer()"
"SMTPC" 5836 5 "2014-06-02 22:15:30.506" "132.245.225.98" "RECEIVED: 250-DB4PR02CA0035.outlook.office365.com Hello [86.130.98.117]"
"DEBUG" 5836 "2014-06-02 22:15:30.507" "SMTPClientConnection::~_ParseASCII() - 1"
"DEBUG" 5836 "2014-06-02 22:15:30.507" "TCPConnection::Read next_layer()"
"DEBUG" 9088 "2014-06-02 22:15:30.508" "SMTPClientConnection::_ParseASCII()"
"DEBUG" 9088 "2014-06-02 22:15:30.508" "TCPCconnection::GetSocket(): next_layer()"
"SMTPC" 9088 5 "2014-06-02 22:15:30.509" "132.245.225.98" "RECEIVED: 250-SIZE 78643200"
"DEBUG" 9088 "2014-06-02 22:15:30.509" "SMTPClientConnection::~_ParseASCII() - 1"
"DEBUG" 9088 "2014-06-02 22:15:30.510" "TCPConnection::Read next_layer()"
"DEBUG" 5836 "2014-06-02 22:15:30.510" "SMTPClientConnection::_ParseASCII()"
"DEBUG" 5836 "2014-06-02 22:15:30.511" "TCPCconnection::GetSocket(): next_layer()"
"SMTPC" 5836 5 "2014-06-02 22:15:30.512" "132.245.225.98" "RECEIVED: 250-PIPELINING"
"DEBUG" 5836 "2014-06-02 22:15:30.512" "SMTPClientConnection::~_ParseASCII() - 1"
"DEBUG" 5836 "2014-06-02 22:15:30.513" "TCPConnection::Read next_layer()"
"DEBUG" 9088 "2014-06-02 22:15:30.513" "SMTPClientConnection::_ParseASCII()"
"DEBUG" 9088 "2014-06-02 22:15:30.514" "TCPCconnection::GetSocket(): next_layer()"
"SMTPC" 9088 5 "2014-06-02 22:15:30.515" "132.245.225.98" "RECEIVED: 250-DSN"
"DEBUG" 9088 "2014-06-02 22:15:30.515" "SMTPClientConnection::~_ParseASCII() - 1"
"DEBUG" 9088 "2014-06-02 22:15:30.516" "TCPConnection::Read next_layer()"
"DEBUG" 5836 "2014-06-02 22:15:30.517" "SMTPClientConnection::_ParseASCII()"
"DEBUG" 5836 "2014-06-02 22:15:30.518" "TCPCconnection::GetSocket(): next_layer()"
"SMTPC" 5836 5 "2014-06-02 22:15:30.518" "132.245.225.98" "RECEIVED: 250-ENHANCEDSTATUSCODES"
"DEBUG" 5836 "2014-06-02 22:15:30.519" "SMTPClientConnection::~_ParseASCII() - 1"
"DEBUG" 5836 "2014-06-02 22:15:30.520" "TCPConnection::Read next_layer()"
"DEBUG" 9088 "2014-06-02 22:15:30.520" "SMTPClientConnection::_ParseASCII()"
"DEBUG" 9088 "2014-06-02 22:15:30.521" "TCPCconnection::GetSocket(): next_layer()"
"SMTPC" 9088 5 "2014-06-02 22:15:30.521" "132.245.225.98" "RECEIVED: 250-STARTTLS"
"DEBUG" 9088 "2014-06-02 22:15:30.522" "SMTPClientConnection::~_ParseASCII() - 1"
"DEBUG" 9088 "2014-06-02 22:15:30.522" "TCPConnection::Read next_layer()"
"DEBUG" 5836 "2014-06-02 22:15:30.523" "SMTPClientConnection::_ParseASCII()"
"DEBUG" 5836 "2014-06-02 22:15:30.524" "TCPCconnection::GetSocket(): next_layer()"
"SMTPC" 5836 5 "2014-06-02 22:15:30.524" "132.245.225.98" "RECEIVED: 250-8BITMIME"
"DEBUG" 5836 "2014-06-02 22:15:30.525" "SMTPClientConnection::~_ParseASCII() - 1"
"DEBUG" 5836 "2014-06-02 22:15:30.525" "TCPConnection::Read next_layer()"
"DEBUG" 9088 "2014-06-02 22:15:30.526" "SMTPClientConnection::_ParseASCII()"
"DEBUG" 9088 "2014-06-02 22:15:30.526" "TCPCconnection::GetSocket(): next_layer()"
"SMTPC" 9088 5 "2014-06-02 22:15:30.527" "132.245.225.98" "RECEIVED: 250-BINARYMIME"
"DEBUG" 9088 "2014-06-02 22:15:30.528" "SMTPClientConnection::~_ParseASCII() - 1"
"DEBUG" 9088 "2014-06-02 22:15:30.528" "TCPConnection::Read next_layer()"
"DEBUG" 5836 "2014-06-02 22:15:30.529" "SMTPClientConnection::_ParseASCII()"
"DEBUG" 5836 "2014-06-02 22:15:30.529" "TCPCconnection::GetSocket(): next_layer()"
"SMTPC" 5836 5 "2014-06-02 22:15:30.530" "132.245.225.98" "RECEIVED: 250 CHUNKING"
"DEBUG" 5836 "2014-06-02 22:15:30.530" "TCPCconnection::GetSocket(): next_layer()"
"SMTPC" 5836 5 "2014-06-02 22:15:30.531" "132.245.225.98" "SENT: STARTTLS"
"DEBUG" 5836 "2014-06-02 22:15:30.531" "TCPConnection::Write next_layer()"
"DEBUG" 5836 "2014-06-02 22:15:30.532" "TCPConnection::STARTTLS_Handshake handshake1"
"DEBUG" 5836 "2014-06-02 22:15:30.533" "TCPConnection::STARTTLS_Handshake handshake3"
"DEBUG" 5836 "2014-06-02 22:15:30.533" "STARTTLS true"
"DEBUG" 5836 "2014-06-02 22:15:30.534" "sleeping 2 sec"
"DEBUG" 8900 "2014-06-02 22:15:30.552" "TCPCconnection::GetSocket(): next_layer()"
"DEBUG" 5836 "2014-06-02 22:15:32.535" "_stateSTARTTLS = 3"
"DEBUG" 5836 "2014-06-02 22:15:32.535" "StartTLSState3() true"
"DEBUG" 5836 "2014-06-02 22:15:32.536" "TCPCconnection::GetSocket(): lowest_layer()"
"SMTPC" 5836 5 "2014-06-02 22:15:32.537" "132.245.225.98" "SENT: EHLO HORSE"
"DEBUG" 9088 "2014-06-02 22:15:32.537" "TCPConnection::Write ssl"
"DEBUG" 5836 "2014-06-02 22:15:32.538" "TCPCconnection::GetSocket(): lowest_layer()"
"DEBUG" 5836 "2014-06-02 22:15:32.538" "The write operation failed. Remote IP: 132.245.225.98, Session: 5, Code: 336031996, Message: unknown protocol"
"DEBUG" 9768 "2014-06-02 22:15:32.539" "SD::~_InitiateExternalConnection-5"
"DEBUG" 9768 "2014-06-02 22:15:32.540" "Ending session 5"
"DEBUG" 9768 "2014-06-02 22:15:32.540" "SD::~_DeliverToExternalAccounts-2"
"DEBUG" 9768 "2014-06-02 22:15:32.541" "Collect delivery result"
"DEBUG" 9768 "2014-06-02 22:15:32.541" "Collect delivery result - Done"
"DEBUG" 9768 "2014-06-02 22:15:32.542" "SD::_RescheduleDelivery"
"DEBUG" 9768 "2014-06-02 22:15:32.542" "Retrieving retry options."
"DEBUG" 9768 "2014-06-02 22:15:32.544" "Starting rescheduling."
"APPLICATION" 9768 "2014-06-02 22:15:32.544" "SMTPDeliverer - Message 3: Message could not be delivered. Scheduling it for later delivery in 60 minutes."
"DEBUG" 9768 "2014-06-02 22:15:32.545" "PersistentMessage::SetNextTryTime()"
"DEBUG" 9768 "2014-06-02 22:15:32.547" "PersistentMessage::~SetNextTryTime()"
"DEBUG" 9768 "2014-06-02 22:15:32.548" "Message rescheduled for later delivery."
"APPLICATION" 9768 "2014-06-02 22:15:32.549" "SMTPDeliverer - Message 3: Message delivery thread completed."
- Attachments
-
- failedsend.zip
- Wireshark Log
- (5.14 KiB) Downloaded 289 times
Last edited by drsox on 2014-06-02 23:43, edited 1 time in total.
Re: ssl/tls and starttls [50%]
thx but i don't see wireshark attachmentdrsox wrote:Wireshark attached below. Looks like the server says hi and then hmailserver ends the connection?
and your logs look like mine now. i assume if connection drops it's because handshake fails but again i've not been able to track it down.
hMailServer build LIVE on my servers: 5.4-B2014050402
#hmailserver on FreeNode IRC https://webchat.freenode.net/?channels=#hmailserver
*** ABSENT FROM hMail! Those in IRC know how to find me if urgent. ***
#hmailserver on FreeNode IRC https://webchat.freenode.net/?channels=#hmailserver
*** ABSENT FROM hMail! Those in IRC know how to find me if urgent. ***
Re: ssl/tls and starttls [50%]
wireshark log attached, I didn't notice it reject the non-ziped version earlier.
Re: ssl/tls and starttls [50%]
thx but not sure what you sent in that vncpng or some weird extensiondrsox wrote:wireshark log attached, I didn't notice it reject the non-ziped version earlier.
hMailServer build LIVE on my servers: 5.4-B2014050402
#hmailserver on FreeNode IRC https://webchat.freenode.net/?channels=#hmailserver
*** ABSENT FROM hMail! Those in IRC know how to find me if urgent. ***
#hmailserver on FreeNode IRC https://webchat.freenode.net/?channels=#hmailserver
*** ABSENT FROM hMail! Those in IRC know how to find me if urgent. ***
Re: ssl/tls and starttls [50%]
It is just the default format that my wireshark 1.10.7 saves in.
Re: ssl/tls and starttls [50%]
oh gotcha not used wireshark in forever. fig'd you were posting a screenshot/image of it.drsox wrote:It is just the default format that my wireshark 1.10.7 saves in.
thx
Bill
hMailServer build LIVE on my servers: 5.4-B2014050402
#hmailserver on FreeNode IRC https://webchat.freenode.net/?channels=#hmailserver
*** ABSENT FROM hMail! Those in IRC know how to find me if urgent. ***
#hmailserver on FreeNode IRC https://webchat.freenode.net/?channels=#hmailserver
*** ABSENT FROM hMail! Those in IRC know how to find me if urgent. ***
Re: ssl/tls and starttls [50%]
Hi Bill,
thank you for mentioning this experimental build in the other thread, i finally found this one after some searching
(sadly i still have no download link and would be happy to have one!
)
I just did some research on the openssl error code and found something that could be the problem in our case:
I have just tested gmail and they seem to support any TLS Protocol i know (tested using openssl for windows from http://slproweb.com/products/Win32OpenSSL.html ).
Following tests worked and established an encrypted connection with TLS1, TLS1.1 and TLS1.2:
openssl s_client -starttls smtp -crlf -tls1 -connect 74.125.136.26:25
openssl s_client -starttls smtp -crlf -tls1_1 -connect 74.125.136.26:25
openssl s_client -starttls smtp -crlf -tls1_2 -connect 74.125.136.26:25
(connection can be soft-terminated by entering "QUIT")
Looking forward to solving this problem
Best regards,
Jan
thank you for mentioning this experimental build in the other thread, i finally found this one after some searching

(sadly i still have no download link and would be happy to have one!

I just did some research on the openssl error code and found something that could be the problem in our case:
(from https://groups.google.com/a/chromium.or ... RvdnUps37Q )"TCPIP" 964 "2014-05-21 22:58:27.957" "TCPConnection - SSL handshake with client failed. Error code: 336031996, Message: unknown protocol, Remote IP: 74.125.193.109"
So, if i am correct, the error means that the gmail servers are not offering any of the SSL/TLS protocol versions, which hMail tries to use (what is enabled in hMailServer? could you please provide the used source/commands/calls with the affected openssl configuration?).No ciphers enabled:
336019637 OpenSSL SSL error, reason: 181, name: error:140740B5:SSL
routines:SSL23_CLIENT_HELLO:no ciphers available
No client/server cipher overlap:
336032784 OpenSSL SSL error, reason: 1040, name: error:14077410:SSL
routines:SSL23_GET_SERVER_HELLO:sslv3 alert handshake failure
No protocol version overlap:
336031996 OpenSSL SSL error, reason: 252, name: error:140770FC:SSL
routines:SSL23_GET_SERVER_HELLO:unknown protocol
I have just tested gmail and they seem to support any TLS Protocol i know (tested using openssl for windows from http://slproweb.com/products/Win32OpenSSL.html ).
Following tests worked and established an encrypted connection with TLS1, TLS1.1 and TLS1.2:
openssl s_client -starttls smtp -crlf -tls1 -connect 74.125.136.26:25
openssl s_client -starttls smtp -crlf -tls1_1 -connect 74.125.136.26:25
openssl s_client -starttls smtp -crlf -tls1_2 -connect 74.125.136.26:25
(connection can be soft-terminated by entering "QUIT")
Looking forward to solving this problem

Best regards,
Jan
Re: ssl/tls and starttls [50%]
Yeah I gathered the same thing Jan it's like the handshake can't complete because the 2 sides can't come up with compatible options.
I think I had only PM'd this to people who requested it. I can't say this enough:
*** DO NOT USE *** *** DO NOT USE *** DO NOT USE** ** DO NOT USE *** *** DO NOT USE *** DO NOT USE**
THIS DOES NOT WORK - Is it for TESTING of outgoing SMTP STARTTLS handshakes.
To test you setup a route & enable SSL. Any email sent thru that route will attempt STARTTLS handshake
*** SSL IS BROKEN IN THIS BUILD ***
*** DO NOT USE *** *** DO NOT USE *** DO NOT USE** ** DO NOT USE *** *** DO NOT USE *** DO NOT USE**
* THIS DOES NOT WORK - Is it for TESTING of outgoing SMTP STARTTLS handshakes.
To test you setup a route & enable SSL. Any email sent thru that route will attempt STARTTLS handshake
*** SSL IS BROKEN IN THIS BUILD **
*** DO NOT USE *** *** DO NOT USE *** DO NOT USE** ** DO NOT USE *** *** DO NOT USE *** DO NOT USE**
I think I had only PM'd this to people who requested it. I can't say this enough:
*** DO NOT USE *** *** DO NOT USE *** DO NOT USE** ** DO NOT USE *** *** DO NOT USE *** DO NOT USE**
THIS DOES NOT WORK - Is it for TESTING of outgoing SMTP STARTTLS handshakes.
To test you setup a route & enable SSL. Any email sent thru that route will attempt STARTTLS handshake
*** SSL IS BROKEN IN THIS BUILD ***
*** DO NOT USE *** *** DO NOT USE *** DO NOT USE** ** DO NOT USE *** *** DO NOT USE *** DO NOT USE**
*** DO NOT USE *** *** DO NOT USE *** DO NOT USE** ** DO NOT USE *** *** DO NOT USE *** DO NOT USE**Bill48105 wrote:Realize this does not work even if you get handshake working it still may not work (tough when I couldn't get past the handshake lol) but yeah if you can test & provide insight into why handshake fails that'll be super helpful.
http://www.mediafire.com/download/j6zpq ... NOT-USE.7z
MD5: 4b33ef43922546815aa60e44e1e5a549 SHA1: 672ae3a01495d516d5c923ec44a552a06c7196b5
There is nothing special to configure (except maybe the new SSL INI's) since this build uses STARTTLS for routes and only routes. No way to turn off. (Not like it matters this is test build and not for real use anyway). So just add a route then send an email & check the logs. I tested to my own hmail & to gmail & both fail after STARTTLS being sent with various handshake errors.
Thx
Bill
* THIS DOES NOT WORK - Is it for TESTING of outgoing SMTP STARTTLS handshakes.
To test you setup a route & enable SSL. Any email sent thru that route will attempt STARTTLS handshake
*** SSL IS BROKEN IN THIS BUILD **
*** DO NOT USE *** *** DO NOT USE *** DO NOT USE** ** DO NOT USE *** *** DO NOT USE *** DO NOT USE**
hMailServer build LIVE on my servers: 5.4-B2014050402
#hmailserver on FreeNode IRC https://webchat.freenode.net/?channels=#hmailserver
*** ABSENT FROM hMail! Those in IRC know how to find me if urgent. ***
#hmailserver on FreeNode IRC https://webchat.freenode.net/?channels=#hmailserver
*** ABSENT FROM hMail! Those in IRC know how to find me if urgent. ***
Re: ssl/tls and starttls [50%]
Hi Bill,
i have not yet found an obvious error in the handshake messages, but i have noticed that one time during my tests TLS was initialized too early by hMailServer.
hMailServer did not wait until the other server replied with "220 Ready to start TLS".
It does not always happen, but is in indication that hMailServer is not waiting correctly before beginning the handshake. Maybe the SMTP Command "220 Ready to start TLS" is then interpreted as handshake reply, which leads to the "unknown protocol" error (trying to start TLS on non-TLS streams is also an common cause for this error).
Probably this only happens if the server sends an zero length [ACK] TCP packet before his SMTP reply.
(Screenshot of the error in wireshark:)

Corresponding log entries:
Is your experimental build source code maintained online? I would be happy to take a look at it during testing (it is handy to know which debug messages are followed by which commands)
Kind regards,
Jan
i have not yet found an obvious error in the handshake messages, but i have noticed that one time during my tests TLS was initialized too early by hMailServer.
hMailServer did not wait until the other server replied with "220 Ready to start TLS".
It does not always happen, but is in indication that hMailServer is not waiting correctly before beginning the handshake. Maybe the SMTP Command "220 Ready to start TLS" is then interpreted as handshake reply, which leads to the "unknown protocol" error (trying to start TLS on non-TLS streams is also an common cause for this error).
Probably this only happens if the server sends an zero length [ACK] TCP packet before his SMTP reply.
(Screenshot of the error in wireshark:)
Corresponding log entries:
Code: Select all
"74.125.142.27" "RECEIVED: 250-mx.google.com at your service, [91.205.173.82]"
[...]
"74.125.142.27" "RECEIVED: 250-ENHANCEDSTATUSCODES"
"SMTPClientConnection::~_ParseASCII() - 1"
"TCPConnection::Read next_layer()"
"SMTPClientConnection::_ParseASCII()"
"TCPCconnection::GetSocket(): next_layer()"
"74.125.142.27" "RECEIVED: 250 CHUNKING"
"TCPCconnection::GetSocket(): next_layer()"
"74.125.142.27" "SENT: STARTTLS"
"TCPConnection::Write next_layer()"
"TCPConnection::STARTTLS_Handshake handshake1"
"TCPConnection::STARTTLS_Handshake handshake3"
"STARTTLS true"
"sleeping 2 sec"
"TCPCconnection::GetSocket(): next_layer()"
"TCPConnection - SSL handshake with client failed. Error code: 336031996, Message: unknown protocol, Remote IP: 74.125.142.27"

Kind regards,
Jan
Re: ssl/tls and starttls [50%]
Hey Jan,japi wrote:Hi Bill,
i have not yet found an obvious error in the handshake messages, but i have noticed that one time during my tests TLS was initialized too early by hMailServer.
hMailServer did not wait until the other server replied with "220 Ready to start TLS".
It does not always happen, but is in indication that hMailServer is not waiting correctly before beginning the handshake. Maybe the SMTP Command "220 Ready to start TLS" is then interpreted as handshake reply, which leads to the "unknown protocol" error (trying to start TLS on non-TLS streams is also an common cause for this error).
Probably this only happens if the server sends an zero length [ACK] TCP packet before his SMTP reply.
(Screenshot of the error in wireshark:)
Corresponding log entries:Is your experimental build source code maintained online? I would be happy to take a look at it during testing (it is handy to know which debug messages are followed by which commands)Code: Select all
"74.125.142.27" "RECEIVED: 250-mx.google.com at your service, [91.205.173.82]" [...] "74.125.142.27" "RECEIVED: 250-ENHANCEDSTATUSCODES" "SMTPClientConnection::~_ParseASCII() - 1" "TCPConnection::Read next_layer()" "SMTPClientConnection::_ParseASCII()" "TCPCconnection::GetSocket(): next_layer()" "74.125.142.27" "RECEIVED: 250 CHUNKING" "TCPCconnection::GetSocket(): next_layer()" "74.125.142.27" "SENT: STARTTLS" "TCPConnection::Write next_layer()" "TCPConnection::STARTTLS_Handshake handshake1" "TCPConnection::STARTTLS_Handshake handshake3" "STARTTLS true" "sleeping 2 sec" "TCPCconnection::GetSocket(): next_layer()" "TCPConnection - SSL handshake with client failed. Error code: 336031996, Message: unknown protocol, Remote IP: 74.125.142.27"
![]()
Kind regards,
Jan
Hmm ok thanks that could be it. The starttls stuff was just hacked up SSL to get something to test & since that would not be waited for for SSL it wouldn't be there for starttls yet. SO yeah that could be very helpful thanks.
Sorry not yet. hmail was on SVN before & I used tortoise to compare mine to official & commit my changes in batches to make sure the result was buildable. martin moved hmail to github before i had a chance to get my changes in then moved hosting so now SVN is gone & I have no easy way to compare them. I planned to get them as close as possible before posting mine as a fork of the official. I still could post mine but it'd be a nightmare for someone else (martin) to merge them especially since he's made changes to the official since moving to github.
Thanks,
Bill
hMailServer build LIVE on my servers: 5.4-B2014050402
#hmailserver on FreeNode IRC https://webchat.freenode.net/?channels=#hmailserver
*** ABSENT FROM hMail! Those in IRC know how to find me if urgent. ***
#hmailserver on FreeNode IRC https://webchat.freenode.net/?channels=#hmailserver
*** ABSENT FROM hMail! Those in IRC know how to find me if urgent. ***
Re: ssl/tls and starttls [50%]
Just FYI, I'm in the middle of adding STARTTLS to hMailServer official builds.
So far I have SMTP Client -> Server and POP3 Client-> Server up and running.
So far I have SMTP Client -> Server and POP3 Client-> Server up and running.
Re: ssl/tls and starttls [50%]
What is the guessimate on when there will be a hMailServer with starttls? Today I ran into the 'Must issue a STARTTLS command first' on passing a message to gmail port 587.
Re: ssl/tls and starttls [50%]
Available in current Beta >>https://www.hmailserver.com/download?pa ... loadid=225
Due for release in weeks
Due for release in weeks
Just 'cause I link to a page and say little else doesn't mean I am not being nice.
https://www.hmailserver.com/documentation
https://www.hmailserver.com/documentation
Re: ssl/tls and starttls [50%]
Thank you. I just tested it and it works!
Many thanks for all your effort.
Many thanks for all your effort.