0 votes
by (900 points)
edited

One of our customers is having an issue connection to a POP3 server via SSL. The log is:

28.03.2014 09:36:42.708 - Connecting to pop.1und1.de:995 using Pop3 2.0.5198.1.
28.03.2014 09:36:42.801 - Connection succeeded.
28.03.2014 09:36:42.813 - Upgrading connection to TLS/SSL.
28.03.2014 09:36:42.839 - State StateChange:Negotiating
28.03.2014 09:36:42.840 - HandshakeMessage:ClientHello was sent.
28.03.2014 09:36:42.886 - HandshakeMessage:ServerHello was received.
28.03.2014 09:36:42.890 - HandshakeMessage:Certificate was received.
28.03.2014 09:36:42.890 - HandshakeMessage:ServerHelloDone was received.
28.03.2014 09:36:42.894 - Verifying server certificate ('CN=pop.1und1.de, O=1 und 1 
Internet AG, L=Montabaur, S=Rhineland-Palatinate, C=DE').
28.03.2014 09:37:57.953 - Certificate verification result: RevocationCheckFailed
28.03.2014 09:37:57.960 - Error while processing TLS packet: Rebex.Net.TlsException: 
Unable to perform revocation check of the server certificate.
   bei Rebex.Net.XY.ZD(String A, CertificateChain B)
   bei Rebex.Net.XY.BE(Byte[] A, Int32 B, Int32 C, IY D)
   bei Rebex.Net.XY.IC(Byte[] A, Int32 B, Int32 C)
   bei Rebex.Net.WY.ZC(Byte[] A, Int32 B, Int32 C)
   bei Rebex.Net.WY.ED()

28.03.2014 09:37:57.962 - Alert Alert:Alert was sent.
28.03.2014 09:37:57.963 - State StateChange:Closed
28.03.2014 09:37:57.965 - Closing TLS socket.
28.03.2014 09:37:57.966 - State changed from 'Connecting' to 'Disconnected'.

Could it be a firewall issue? Do you know which ports are being used to validate a certificate online? Or what else can we do (besides setting SslAcceptAllCertificates to true)?

Applies to: Rebex Secure Mail

4 Answers

0 votes
by (58.9k points)
edited

RevocationCheckFailed indicates that the OS was unable to retrieve a certificate revocation list (CRL) from the server certificate's issuer and perform a check to determine whether the server certificate has been revoked.

To retrieve the CRL, the OS has to be able to connect to the Internet (usually using HTTP or LDAP protocols), and if this is not possible, revocation check would fail.

There is a built-in utility in Windows called certutil which you can run to see what's wrong. First, download the server certificate using the following code:

Pop3 client = new Pop3();
client.Settings.SslAcceptAllCertificates = true;
client.Connect("server", SslMode.Implicit);
client.TlsSocket.ServerCertificate[0].Save("cert.der", CertificateFormat.Base64Der);

Then, tun the certutil command line utility on the downloaded cert.der file:

certutil -verify -urlfetch cert.der

Please check its output to see whats wrong, and send us a copy if possible.

0 votes
by (900 points)
edited

Here is the log, but I can't really determine if there was an error or not. Can you see something?

Aussteller:
    CN=Thawte SSL CA
    O=Thawte, Inc.
    C=US
Antragsteller:
    CN=smtp.1und1.de
    O=1 und 1 Internet AG
    L=Montabaur
    S=Rhineland-Palatinate
    C=DE
Zertifikatseriennummer: 4dcc76eefbf9835f0de8724a8ee8afb9

dwFlags = CA_VERIFY_FLAGS_CONSOLE_TRACE (0x20000000)
dwFlags = CA_VERIFY_FLAGS_DUMP_CHAIN (0x40000000)
ChainFlags = CERT_CHAIN_REVOCATION_CHECK_CHAIN_EXCLUDE_ROOT (0x40000000)
HCCE_LOCAL_MACHINE
CERT_CHAIN_POLICY_BASE
-------- CERT_CHAIN_CONTEXT --------
ChainContext.dwInfoStatus = CERT_TRUST_HAS_PREFERRED_ISSUER (0x100)
ChainContext.dwRevocationFreshnessTime: 3 Days, 16 Hours, 15 Minutes, 33 Seconds

SimpleChain.dwInfoStatus = CERT_TRUST_HAS_PREFERRED_ISSUER (0x100)
SimpleChain.dwRevocationFreshnessTime: 3 Days, 16 Hours, 15 Minutes, 33 Seconds

CertContext[0][0]: dwInfoStatus=102 dwErrorStatus=0
  Issuer: CN=Thawte SSL CA, O="Thawte, Inc.", C=US
  NotBefore: 20.03.2013 01:00
  NotAfter: 16.04.2014 00:59
  Subject: CN=smtp.1und1.de, O=1 und 1 Internet AG, L=Montabaur, S=Rhineland-Palatinate, C=DE
  Serial: 4dcc76eefbf9835f0de8724a8ee8afb9
  SubjectAltName: DNS-Name=smtp.1und1.de
  94 52 fb fc 9c 22 25 d8 c5 3a 79 e1 c7 42 e4 1c 21 2d 14 ea
  Element.dwInfoStatus = CERT_TRUST_HAS_KEY_MATCH_ISSUER (0x2)
  Element.dwInfoStatus = CERT_TRUST_HAS_PREFERRED_ISSUER (0x100)
  ----------------  Zertifikat abrufen  ----------------
  Überprüft "Zertifikat (0)" Zeit: 4
    [0.0] http://svr-ov-aia.thawte.com/ThawteOV.cer

  ----------------  Zertifikat abrufen  ----------------
  Überprüft "Basissperrliste (0b3a)" Zeit: 4
    [0.0] http://svr-ov-crl.thawte.com/ThawteOV.crl

  ----------------  Basissperrliste veraltet  ----------------
  Keine URLs "Keine" Zeit: 0
  ----------------  Zertifikat-OCSP  ----------------
  Überprüft "OCSP" Zeit: 5
    [0.0] http://ocsp.thawte.com

  --------------------------------
    CRL (null):
    Issuer: CN=Thawte SSL OCSP Responder, O="Thawte, Inc.", C=US
    c7 d9 f9 5e 6e ba 2a 88 75 3f 87 90 49 f1 49 56 b8 01 e2 c4
  Application[0] = 1.3.6.1.5.5.7.3.1 Serverauthentifizierung
  Application[1] = 1.3.6.1.5.5.7.3.2 Clientauthentifizierung

CertContext[0][1]: dwInfoStatus=102 dwErrorStatus=0
  Issuer: CN=thawte Primary Root CA, OU="(c) 2006 thawte, Inc. - For authorized use only", OU=Certification Services Division, O="thawte, Inc.", C=US
  NotBefore: 08.02.2010 01:00
  NotAfter: 08.02.2020 00:59
  Subject: CN=Thawte SSL CA, O="Thawte, Inc.", C=US
  Serial: 4d5f2c3408b24c20cd6d507e244dc9ec
  SubjectAltName: Verzeichnisadresse:CN=VeriSignMPKI-2-9
  73 e4 26 86 65 7a ec e3 54 fb f6 85 71 23 61 65 8f 2f 43 57
  Element.dwInfoStatus = CERT_TRUST_HAS_KEY_MATCH_ISSUER (0x2)
  Element.dwInfoStatus = CERT_TRUST_HAS_PREFERRED_ISSUER (0x100)
  ----------------  Zertifikat abrufen  ----------------
  Keine URLs "Keine" Zeit: 0
  ----------------  Zertifikat abrufen  ----------------
  Überprüft "Basissperrliste" Zeit: 4
    [0.0] http://crl.thawte.com/ThawtePCA.crl

  ----------------  Basissperrliste veraltet  ----------------
  Keine URLs "Keine" Zeit: 0
  ----------------  Zertifikat-OCSP  ----------------
  Überprüft "OCSP" Zeit: 4
    [0.0] http://ocsp.thawte.com

  --------------------------------
    CRL (null):
    Issuer: CN=thawte Primary Root OCSP Responder Certificate 2, O="thawte, Inc.", C=US
    ab 77 ce d6 bc 03 ac f2 1d 0a 36 aa a0 30 3c 2a 0b 59 f0 f7
  Application[0] = 1.3.6.1.5.5.7.3.1 Serverauthentifizierung
  Application[1] = 1.3.6.1.5.5.7.3.2 Clientauthentifizierung
  Application[2] = 1.3.6.1.5.5.7.3.4 Sichere E-Mail
  Application[3] = 1.3.6.1.5.5.7.3.3 Codesignatur

CertContext[0][2]: dwInfoStatus=10c dwErrorStatus=0
  Issuer: CN=thawte Primary Root CA, OU="(c) 2006 thawte, Inc. - For authorized use only", OU=Certification Services Division, O="thawte, Inc.", C=US
  NotBefore: 17.11.2006 01:00
  NotAfter: 17.07.2036 00:59
  Subject: CN=thawte Primary Root CA, OU="(c) 2006 thawte, Inc. - For authorized use only", OU=Certification Services Division, O="thawte, Inc.", C=US
  Serial: 344ed55720d5edec49f42fce37db2b6d
  91 c6 d6 ee 3e 8a c8 63 84 e5 48 c2 99 29 5c 75 6c 81 7b 81
  Element.dwInfoStatus = CERT_TRUST_HAS_NAME_MATCH_ISSUER (0x4)
  Element.dwInfoStatus = CERT_TRUST_IS_SELF_SIGNED (0x8)
  Element.dwInfoStatus = CERT_TRUST_HAS_PREFERRED_ISSUER (0x100)
  ----------------  Zertifikat abrufen  ----------------
  Keine URLs "Keine" Zeit: 0
  ----------------  Zertifikat abrufen  ----------------
  Keine URLs "Keine" Zeit: 0
  ----------------  Zertifikat-OCSP  ----------------
  Keine URLs "Keine" Zeit: 0
  --------------------------------
  Application[0] = 1.3.6.1.5.5.7.3.1 Serverauthentifizierung
  Application[1] = 1.3.6.1.5.5.7.3.2 Clientauthentifizierung
  Application[2] = 1.3.6.1.5.5.7.3.4 Sichere E-Mail
  Application[3] = 1.3.6.1.5.5.7.3.3 Codesignatur

Exclude leaf cert:
  ef 61 a5 a0 70 7f cf e8 0c 26 c8 f3 d1 c7 ad 30 84 9f c5 d8
Full chain:
  5d 9b 3e be ff 4b b2 ad 8d b7 04 35 33 2e fc 22 1e 02 5b 10
------------------------------------
Verfizierte Ausstellungsrichtlinien: Kein
Verfizierte Anwendungsrichtlinien:
    1.3.6.1.5.5.7.3.1 Serverauthentifizierung
    1.3.6.1.5.5.7.3.2 Clientauthentifizierung
Das Zertifikat ist ein Endeinheitzertifikat
Sperrstatussüberprüfung des untergeordneten Zertifikats erfolgreich abgeschlossen.
CertUtil: -verify-Befehl wurde erfolgreich ausgeführt.
by (147k points)
edited

This looks like the certificate revocation status was successfully checked and is OK. Was this the same machine and user account under which the Rebex code is running?

If it was, please try using .NET's X509Chain class to validate the certificate and lets us know what it says. You can find the code for that at http://forum.rebex.net/questions/3990/unable-to-perform-revocation-check-of-the-server-certificate/3998 (you can skip the first step)

by (900 points)
edited

According to our customer, this was the same machine. Most likely not the same user as the components are used by a service running as LOCAL SYSTEM by default, whereas the log was produced by an interactive user, obviously. Does this make any difference (except for user based firewalls or something of course)?

by (900 points)
edited

I've compiled a small test utility with the code you mentioned and sent it to our customer, awaiting feedback...

by (147k points)
edited

Running under a different account can indeed make a difference. Would it be possible to run the X509Chain-based code from the service running as LOCAL_SYSTEM? That should make it possible to determine what is going on. If this is not easily possible, please let me know. We might enhance certificate check error logging in the components itself, which would make it possible to tell what exactly is going on from the log itself.

by (900 points)
edited

While it would be possible to incorporate the test code into the service, that wouldn't be our preferred solution. I think enhancing the logging of the components would be beneficial to everyone, including future customers facing the same problem, wouldn't you think?

by (147k points)
edited

Definitely! We enhanced the logging in the component and sent you a link to the current build. Please give it a try.

by (900 points)
edited

The test utility worked just fine on our customer's server. I've mailed the hotfix you provided to them and am awaiting the logs...

0 votes
by (900 points)
edited

Sorry for the delay. Here's the output of the new version:

State changed from 'Disconnected' to 'Connecting'.
Connecting to pop.1und1.de:995 using Pop3 2.0.5198.1.
Connection succeeded.
Upgrading connection to TLS/SSL.
State StateChange:Negotiating
HandshakeMessage:ClientHello was sent.
HandshakeMessage:ServerHello was received.
HandshakeMessage:Certificate was received.
HandshakeMessage:ServerHelloDone was received.
Verifying server certificate ('CN=pop.1und1.de, O=1&1 Internet AG, L=Montabaur, S=Rhineland-Palatinate, C=DE').
Certificate verification result: RevocationCheckFailed
Error while processing TLS packet: Rebex.Net.TlsException: Unable to perform revocation check of the server certificate.
   bei Rebex.Net.XY.ZD(String A, CertificateChain B)
   bei Rebex.Net.XY.BE(Byte[] A, Int32 B, Int32 C, IY D)
   bei Rebex.Net.XY.IC(Byte[] A, Int32 B, Int32 C)
   bei Rebex.Net.WY.ZC(Byte[] A, Int32 B, Int32 C)
   bei Rebex.Net.WY.ED()
Alert Alert:Alert was sent.
State StateChange:Closed
Closing TLS socket.
State changed from 'Connecting' to 'Disconnected'.
Rebex.Net.TlsException: Unable to perform revocation check of the server certificate. ---> Rebex.Net.TlsException: Unable to perform revocation check of the server certificate.
   bei Rebex.Net.XY.ZD(String A, CertificateChain B)
   bei Rebex.Net.XY.BE(Byte[] A, Int32 B, Int32 C, IY D)
   bei Rebex.Net.XY.IC(Byte[] A, Int32 B, Int32 C)
   bei Rebex.Net.WY.ZC(Byte[] A, Int32 B, Int32 C)
   bei Rebex.Net.WY.ED()
   --- Ende der internen Ausnahmestapelüberwachung ---
   bei Rebex.Net.WY.ED()
   bei Rebex.Net.WY.MD()
   bei Rebex.Net.TlsSocket.Negotiate()
   bei Rebex.Net.WAB.Z(TlsParameters A)
   bei Rebex.Net.Pop3.PL(String A, Int32 B, TlsParameters C, Pop3Security D)
by (147k points)
edited

Unfortunately, you still seem to be running the old version - enhanced logging was added in '2.0.5204.1' and both the logs above come from '2.0.5198.1'. Please make sure you deployed the new version - you can find the download link in the e-mail of 31st March 2014.

0 votes
by (900 points)
edited

Here is the new log. Unfortunately it doesn't say/show that the verification fails, but now it can't connect :(

State changed from 'Disconnected' to 'Connecting'.
Connecting to pop.1und1.de:995 using Pop3 2.0.5204.1.
Connection succeeded.
Upgrading connection to TLS/SSL.
State StateChange:Negotiating
HandshakeMessage:ClientHello was sent.
HandshakeMessage:ServerHello was received.
HandshakeMessage:Certificate was received.
HandshakeMessage:ServerHelloDone was received.
Verifying server certificate ('CN=pop.1und1.de, E=server-certs@1und1.de, L=Montabaur, S=Rheinland-Pfalz, O=1 und 1 Internet AG, C=DE').
Certificate verification result: Accept
HandshakeMessage:ClientKeyExchange was sent.
CipherSpec:ChangeCipherSpec was sent.
HandshakeMessage:Finished was sent.
TLS socket was closed, 0 bytes of data were received.
State StateChange:Closed
TLS socket closed while negotiation was in progress.
Closing TLS socket.
State changed from 'Connecting' to 'Disconnected'.
Rebex.Net.TlsException: Secure connection was closed by the remote connection end.
   bei Rebex.Net.WY.MD()
   bei Rebex.Net.WAB.Z(TlsParameters A)
   bei Rebex.Net.Pop3.PL(String A, Int32 B, TlsParameters C, Pop3Security D)
State changed from 'Disconnected' to 'Connecting'.
Connecting to pop.1und1.de:995 using Pop3 2.0.5204.1.
Connection succeeded.
State changed from 'Connecting' to 'Reading'.
by (147k points)
edited

The verification certainly doesn't fail now. Instead, for some reason, the server closes the connection later, just when the SSL channel is about to be negotiated. Does it fail this way every time?

by (900 points)
edited

In the test scenario it failed every time, but that was only tested a couple of minutes. I think we'll leave this as is for now and if other customers have similar issues, I'll get back to you. Thanks!

...