ctrlplane / copilot

Key broker service
GNU General Public License v3.0
1 stars 1 forks source link

copilot fails to connect to mongo after long uptime #19

Open ekwisnek opened 2 years ago

ekwisnek commented 2 years ago

I think this is due to a long uptime, but not sure. Effectively ran an encrypt op multiple times over the course of two days, and the keywrap failed because copilot couldn't connect to MongoDB (I think). Finding it difficult to reproduce.

2022-08-02 19:19:41.288  INFO 1 --- [ngodb.net:27017] org.mongodb.driver.cluster               : Exception in monitor thread while connecting to server ac-1xiam0d-shard-00-02.kb96yfd.mongodb.net:27017

com.mongodb.MongoSocketReadTimeoutException: Timeout while receiving message
        at com.mongodb.internal.connection.InternalStreamConnection.translateReadException(InternalStreamConnection.java:696) ~[mongodb-driver-core-4.6.1.jar:na]
        at com.mongodb.internal.connection.InternalStreamConnection.receiveMessageWithAdditionalTimeout(InternalStreamConnection.java:574) ~[mongodb-driver-core-4.6.1.jar:na]
        at com.mongodb.internal.connection.InternalStreamConnection.receiveCommandMessageResponse(InternalStreamConnection.java:410) ~[mongodb-driver-core-4.6.1.jar:na]
        at com.mongodb.internal.connection.InternalStreamConnection.receive(InternalStreamConnection.java:369) ~[mongodb-driver-core-4.6.1.jar:na]
        at com.mongodb.internal.connection.DefaultServerMonitor$ServerMonitorRunnable.lookupServerDescription(DefaultServerMonitor.java:221) ~[mongodb-driver-core-4.6.1.jar:na]
        at com.mongodb.internal.connection.DefaultServerMonitor$ServerMonitorRunnable.run(DefaultServerMonitor.java:157) ~[mongodb-driver-core-4.6.1.jar:na]
        at java.base/java.lang.Thread.run(Thread.java:833) ~[na:na]
Caused by: java.net.SocketTimeoutException: Read timed out
        at java.base/sun.nio.ch.NioSocketImpl.timedRead(NioSocketImpl.java:283) ~[na:na]
        at java.base/sun.nio.ch.NioSocketImpl.implRead(NioSocketImpl.java:309) ~[na:na]
        at java.base/sun.nio.ch.NioSocketImpl.read(NioSocketImpl.java:350) ~[na:na]
        at java.base/sun.nio.ch.NioSocketImpl$1.read(NioSocketImpl.java:803) ~[na:na]
        at java.base/java.net.Socket$SocketInputStream.read(Socket.java:966) ~[na:na]
        at java.base/sun.security.ssl.SSLSocketInputRecord.read(SSLSocketInputRecord.java:478) ~[na:na]
        at java.base/sun.security.ssl.SSLSocketInputRecord.readHeader(SSLSocketInputRecord.java:472) ~[na:na]
        at java.base/sun.security.ssl.SSLSocketInputRecord.bytesInCompletePacket(SSLSocketInputRecord.java:70) ~[na:na]
        at java.base/sun.security.ssl.SSLSocketImpl.readApplicationRecord(SSLSocketImpl.java:1460) ~[na:na]
        at java.base/sun.security.ssl.SSLSocketImpl$AppInputStream.read(SSLSocketImpl.java:1064) ~[na:na]
        at com.mongodb.internal.connection.SocketStream.read(SocketStream.java:110) ~[mongodb-driver-core-4.6.1.jar:na]
        at com.mongodb.internal.connection.SocketStream.read(SocketStream.java:135) ~[mongodb-driver-core-4.6.1.jar:na]
        at com.mongodb.internal.connection.InternalStreamConnection.receiveResponseBuffers(InternalStreamConnection.java:713) ~[mongodb-driver-core-4.6.1.jar:na]
        at com.mongodb.internal.connection.InternalStreamConnection.receiveMessageWithAdditionalTimeout(InternalStreamConnection.java:571) ~[mongodb-driver-core-4.6.1.jar:na]
        ... 5 common frames omitted

2022-08-02 19:19:41.425  INFO 1 --- [ngodb.net:27017] org.mongodb.driver.connection            : Opened connection [connectionId{localValue:132, serverValue:1096}] to ac-1xiam0d-shard-00-02.kb96yfd.mongodb.net:27017
2022-08-02 19:19:41.425  INFO 1 --- [ngodb.net:27017] org.mongodb.driver.cluster               : Monitor thread successfully connected to server with description ServerDescription{address=ac-1xiam0d-shard-00-02.kb96yfd.mongodb.net:27017, type=REPLICA_SET_PRIMARY, state=CONNECTED, ok=true, minWireVersion=0, maxWireVersion=13, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=49918845, setName='atlas-m4n9iw-shard-0', canonicalAddress=ac-1xiam0d-shard-00-02.kb96yfd.mongodb.net:27017, hosts=[ac-1xiam0d-shard-00-00.kb96yfd.mongodb.net:27017, ac-1xiam0d-shard-00-01.kb96yfd.mongodb.net:27017, ac-1xiam0d-shard-00-02.kb96yfd.mongodb.net:27017], passives=[], arbiters=[], primary='ac-1xiam0d-shard-00-02.kb96yfd.mongodb.net:27017', tagSet=TagSet{[Tag{name='nodeType', value='ELECTABLE'}, Tag{name='provider', value='AWS'}, Tag{name='region', value='US_EAST_1'}, Tag{name='workloadType', value='OPERATIONAL'}]}, electionId=7fffffff0000000000000090, setVersion=10, topologyVersion=TopologyVersion{processId=62e9757e578b7785d39396d9, counter=6}, lastWriteDate=Tue Aug 02 19:19:41 GMT 2022, lastUpdateTimeNanos=6898751406682}
2022-08-02 19:19:41.427  INFO 1 --- [ngodb.net:27017] org.mongodb.driver.cluster               : Setting max election id to 7fffffff0000000000000090 from replica set primary ac-1xiam0d-shard-00-02.kb96yfd.mongodb.net:27017
2022-08-02 19:19:41.427  INFO 1 --- [ngodb.net:27017] org.mongodb.driver.cluster               : Discovered replica set primary ac-1xiam0d-shard-00-02.kb96yfd.mongodb.net:27017
2022-08-02 19:19:55.151  INFO 1 --- [ngodb.net:27017] org.mongodb.driver.connection            : Opened connection [connectionId{localValue:133, serverValue:1237}] to ac-1xiam0d-shard-00-00.kb96yfd.mongodb.net:27017
2022-08-02 19:19:55.910  INFO 1 --- [ngodb.net:27017] org.mongodb.driver.connection            : Opened connection [connectionId{localValue:134, serverValue:1138}] to ac-1xiam0d-shard-00-02.kb96yfd.mongodb.net:27017
2022-08-02 19:20:01.334  INFO 1 --- [ngodb.net:27017] org.mongodb.driver.connection            : Opened connection [connectionId{localValue:135, serverValue:1006}] to ac-1xiam0d-shard-00-01.kb96yfd.mongodb.net:27017
2022-08-02 19:20:27.539  INFO 1 --- [ngodb.net:27017] org.mongodb.driver.cluster               : Exception in monitor thread while connecting to server ac-1xiam0d-shard-00-01.kb96yfd.mongodb.net:27017

com.mongodb.MongoSocketReadTimeoutException: Timeout while receiving message
        at com.mongodb.internal.connection.InternalStreamConnection.translateReadException(InternalStreamConnection.java:696) ~[mongodb-driver-core-4.6.1.jar:na]
        at com.mongodb.internal.connection.InternalStreamConnection.receiveMessageWithAdditionalTimeout(InternalStreamConnection.java:574) ~[mongodb-driver-core-4.6.1.jar:na]
        at com.mongodb.internal.connection.InternalStreamConnection.receiveCommandMessageResponse(InternalStreamConnection.java:410) ~[mongodb-driver-core-4.6.1.jar:na]
        at com.mongodb.internal.connection.InternalStreamConnection.receive(InternalStreamConnection.java:369) ~[mongodb-driver-core-4.6.1.jar:na]
        at com.mongodb.internal.connection.DefaultServerMonitor$ServerMonitorRunnable.lookupServerDescription(DefaultServerMonitor.java:221) ~[mongodb-driver-core-4.6.1.jar:na]
        at com.mongodb.internal.connection.DefaultServerMonitor$ServerMonitorRunnable.run(DefaultServerMonitor.java:157) ~[mongodb-driver-core-4.6.1.jar:na]
        at java.base/java.lang.Thread.run(Thread.java:833) ~[na:na]
Caused by: java.net.SocketTimeoutException: Read timed out
        at java.base/sun.nio.ch.NioSocketImpl.timedRead(NioSocketImpl.java:283) ~[na:na]
        at java.base/sun.nio.ch.NioSocketImpl.implRead(NioSocketImpl.java:309) ~[na:na]
        at java.base/sun.nio.ch.NioSocketImpl.read(NioSocketImpl.java:350) ~[na:na]
        at java.base/sun.nio.ch.NioSocketImpl$1.read(NioSocketImpl.java:803) ~[na:na]
        at java.base/java.net.Socket$SocketInputStream.read(Socket.java:966) ~[na:na]
        at java.base/sun.security.ssl.SSLSocketInputRecord.read(SSLSocketInputRecord.java:478) ~[na:na]
        at java.base/sun.security.ssl.SSLSocketInputRecord.readHeader(SSLSocketInputRecord.java:472) ~[na:na]
        at java.base/sun.security.ssl.SSLSocketInputRecord.bytesInCompletePacket(SSLSocketInputRecord.java:70) ~[na:na]
        at java.base/sun.security.ssl.SSLSocketImpl.readApplicationRecord(SSLSocketImpl.java:1460) ~[na:na]
        at java.base/sun.security.ssl.SSLSocketImpl$AppInputStream.read(SSLSocketImpl.java:1064) ~[na:na]
        at com.mongodb.internal.connection.SocketStream.read(SocketStream.java:110) ~[mongodb-driver-core-4.6.1.jar:na]
        at com.mongodb.internal.connection.SocketStream.read(SocketStream.java:135) ~[mongodb-driver-core-4.6.1.jar:na]
        at com.mongodb.internal.connection.InternalStreamConnection.receiveResponseBuffers(InternalStreamConnection.java:713) ~[mongodb-driver-core-4.6.1.jar:na]
        at com.mongodb.internal.connection.InternalStreamConnection.receiveMessageWithAdditionalTimeout(InternalStreamConnection.java:571) ~[mongodb-driver-core-4.6.1.jar:na]
        ... 5 common frames omitted

2022-08-02 19:20:27.658  INFO 1 --- [ngodb.net:27017] org.mongodb.driver.cluster               : Exception in monitor thread while connecting to server ac-1xiam0d-shard-00-00.kb96yfd.mongodb.net:27017

Stack trace for reference.