ctrlplane / ctrlplane/copilot

copilot fails to connect to mongo after long uptime

Aperta
#19 0 commenti 0 reazioni 0 assegnatari Vedi su GitHub
bug help wanted
Lingua principale
Java
Stelle
1
Fork
1
Metriche di merge delle PR
Nessuna PR unita negli ultimi 30g

Descrizione

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.

Guida per i contributori

Nessuna guida per i contributori indicizzata per questo repository

Direzione di ricerca

Inizia tracciando il percorso encrypt/keywrap e la gestione della relativa connessione MongoDB, usando i log di timeout del MongoDB driver forniti come evidenza iniziale. Riproduci il problema dopo un lungo periodo di attività, se possibile, e conferma che la crittografia ripetuta riesca ancora a connettersi a MongoDB senza che si verifichi il problema keywrap segnalato.

Scritto dal modello di indicizzazione a partire dal testo della issue.

Valutazione

Stack tecnologico
java, mongodb
Ambito
backend, databases
Tipo di issue
Bug
Difficoltà
4/5
Tempo stimato
3-5 giorni
Stato di attività
Ferma
Chiarezza
Da chiarire
Idoneità per principianti
25/100

Ricevi le nuove issue nella tua casella

Un breve riepilogo di issue GitHub adatte ai principianti.