cognitect-labs / aws-api

AWS, data driven
Apache License 2.0
730 stars 100 forks source link

Unrecognized record version (D)TLS-0.0 , plaintext connection #139

Open kennyjwilli opened 4 years ago

kennyjwilli commented 4 years ago

We have been getting this issue in production for a while. It happens infrequently but enough that it's an issue. I have been able to reproduce it most often by making lots of concurrent calls with aws-api, which we do a lot of in prod. This issue seems to have something to do with the HTTP client that aws-api uses.

Dependencies

I can provide more deps if needed. The relevent ones seem to be aws-api and client-cloud which brings in the Cognitect http-client.

com.cognitect.aws/api 0.8.456
com.datomic/client-cloud 0.8.91
    com.datomic/client 0.8.97
      com.datomic/client-api 0.8.44
      com.datomic/query-support 0.8.27
    com.datomic/client-impl-shared 0.8.79
      com.cognitect/hmac-authn 0.1.195
      com.cognitect/http-client 0.1.105
        org.eclipse.jetty/jetty-http 9.4.27.v20200227
        org.eclipse.jetty/jetty-util 9.4.27.v20200227
        org.eclipse.jetty/jetty-client 9.4.27.v20200227
          org.eclipse.jetty/jetty-io 9.4.27.v20200227
      com.cognitect/transit-clj 0.8.313
        com.cognitect/transit-java 0.8.337
          org.msgpack/msgpack 0.6.12
            com.googlecode.json-simple/json-simple 1.1.1
            org.javassist/javassist 3.18.1-GA
          javax.xml.bind/jaxb-api 2.3.0
    com.cognitect/s3-creds 0.1.22
    com.datomic/s3-access-keys 0.1.6
    com.amazonaws/aws-java-sdk-s3 1.11.210
      com.amazonaws/aws-java-sdk-kms 1.11.210

Description with failing test case

Don't have a reproducible example. This issue seems to manifest when making lots of calls using aws-api.

Stack traces

(:cognitect.http-client/throwable (ex-data (ex-cause (ex-cause e))))
=>
#error{:cause "Unrecognized record version (D)TLS-0.0 , plaintext connection?",
       :via [{:type javax.net.ssl.SSLException,
              :message "Unrecognized record version (D)TLS-0.0 , plaintext connection?",
              :at [sun.security.ssl.SSLEngineInputRecord bytesInCompletePacket "SSLEngineInputRecord.java" 98]}],
       :trace [[sun.security.ssl.SSLEngineInputRecord bytesInCompletePacket "SSLEngineInputRecord.java" 98]
               [sun.security.ssl.SSLEngineInputRecord bytesInCompletePacket "SSLEngineInputRecord.java" 64]
               [sun.security.ssl.SSLEngineImpl readRecord "SSLEngineImpl.java" 544]
               [sun.security.ssl.SSLEngineImpl unwrap "SSLEngineImpl.java" 441]
               [sun.security.ssl.SSLEngineImpl unwrap "SSLEngineImpl.java" 420]
               [javax.net.ssl.SSLEngine unwrap "SSLEngine.java" 634]
               [org.eclipse.jetty.io.ssl.SslConnection unwrap "SslConnection.java" 417]
               [org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint fill "SslConnection.java" 705]
               [org.eclipse.jetty.client.http.HttpReceiverOverHTTP process "HttpReceiverOverHTTP.java" 159]
               [org.eclipse.jetty.client.http.HttpReceiverOverHTTP receive "HttpReceiverOverHTTP.java" 75]
               [org.eclipse.jetty.client.http.HttpChannelOverHTTP receive "HttpChannelOverHTTP.java" 133]
               [org.eclipse.jetty.client.http.HttpConnectionOverHTTP onFillable "HttpConnectionOverHTTP.java" 156]
               [org.eclipse.jetty.io.AbstractConnection$ReadCallback succeeded "AbstractConnection.java" 311]
               [org.eclipse.jetty.io.FillInterest fillable "FillInterest.java" 103]
               [org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint onFillable "SslConnection.java" 543]
               [org.eclipse.jetty.io.ssl.SslConnection onFillable "SslConnection.java" 398]
               [org.eclipse.jetty.io.ssl.SslConnection$2 succeeded "SslConnection.java" 161]
               [org.eclipse.jetty.io.FillInterest fillable "FillInterest.java" 103]
               [org.eclipse.jetty.io.ChannelEndPoint$2 run "ChannelEndPoint.java" 117]
               [org.eclipse.jetty.util.thread.strategy.EatWhatYouKill runTask "EatWhatYouKill.java" 336]
               [org.eclipse.jetty.util.thread.strategy.EatWhatYouKill doProduce "EatWhatYouKill.java" 313]
               [org.eclipse.jetty.util.thread.strategy.EatWhatYouKill tryProduce "EatWhatYouKill.java" 171]
               [org.eclipse.jetty.util.thread.strategy.EatWhatYouKill run "EatWhatYouKill.java" 129]
               [org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread
                run
                "ReservedThreadExecutor.java"
                375]
               [org.eclipse.jetty.util.thread.QueuedThreadPool runJob "QueuedThreadPool.java" 806]
               [org.eclipse.jetty.util.thread.QueuedThreadPool$Runner run "QueuedThreadPool.java" 938]
               [java.lang.Thread run "Thread.java" 834]]}
ngratzi commented 3 years ago

I am getting this same issue in production. It is very sporadic and I cannot consistently reproduce it.

nnichols commented 3 years ago

I'm facing this issue as well. Is there any resolution, workaround, or plan to fix?

nnichols commented 3 years ago

Is the source for the http-client available anywhere? I'd like to dig into this further, but there does not appear to be a matching repo within the cognitect-labs GitHub organization

nnichols commented 3 years ago

@ngratzi - How frequently are you seeing this occur? It's happening at least daily for every queue for me

kennyjwilli commented 3 years ago

These errors seem to have gone away for us. We used get them at least daily. I don't know what our fix was. I do know that since I created this issue, we have updated our Java version to 11.0.10-11.45.27 and Jetty version to 9.4.40.v20210413.

ngratzi commented 3 years ago

@nnichols - We used to get them daily every morning from 530am PST to 930am PST. They do stop eventually and not every request has this issue (about 5% to 10%). For the past month, we have not had a single issue, up until just recently where we are seeing the same pattern as before (in the morning PST). I have not been able to reproduce consistently or capture any data when this is happening