reportportal/service-authorization

user no longer being able to authenticate after some time

rplevka opened this issue · 7 comments

I'm not sure I'm creating this issue for a correct component, but it seems like it's either UAT or API service issue:

I made a stress-test on my local RP setup, where I kept running a multi-threaded py.test session in a loop.
All tests are designed to log about 100 messages to RP and fail. I use the pytest_reportportal plugin which uses reportportal_agent python api binding library.

Everything seems to work fine up until a certain iteration, where RP stops responding (and the py.test session hangs).

I tried some investigation and it turned out I am no longer able to authenticate to RP:

$ curl -X GET --header 'Accept: application/json' --header 'Authorization: bearer feee450c-401d-40a1-854d-96c42672701c' 'http://localhost:8080/api/v1/user'
{"error":"invalid_token","error_description":"feee450c-401d-40a1-854d-96c42672701c"}

this is the message logged by API service:

api_1            | 2018-11-03 10:39:21.189  WARN 1 --- [nio-8080-exec-6] o.s.b.a.s.o.r.UserInfoTokenServices      : Could not fetch user details: class java.lang.IllegalStateException, No instances available for uat

Anyway, all services seem to be running (ignore the API service runtime - i tried to restart it to see whether it helps):

$ docker ps
CONTAINER ID        IMAGE                                                     COMMAND                  CREATED             STATUS              PORTS                                                                      NAMES
59ca520a4b61        reportportal/service-api:4.3.0                            "/start.sh"              11 hours ago        Up 2 hours          8080/tcp                                                                   reportportal_api_1
32381286b788        reportportal/service-authorization:4.2.0                  "/start.sh"              11 hours ago        Up 11 hours         8080/tcp                                                                   reportportal_uat_1
197b7546be0b        reportportal/service-index:4.2.0                          "/service-index"         11 hours ago        Up 11 hours         8080/tcp                                                                   reportportal_index_1
d78a30acd879        reportportal/service-analyzer:4.3.0                       "/service-analyzer"      11 hours ago        Up 11 hours         8080/tcp                                                                   reportportal_analyzer_1
7d7f6935a826        consul:1.0.6                                              "docker-entrypoint..."   11 hours ago        Up 11 hours         8300-8302/tcp, 8301-8302/udp, 8600/tcp, 8600/udp, 0.0.0.0:8500->8500/tcp   reportportal_registry_1
7d0235fe22a9        mongo:3.4                                                 "docker-entrypoint..."   11 hours ago        Up 11 hours         27017/tcp                                                                  reportportal_mongodb_1
3f58df7f64cd        reportportal/service-jira:4.3.0                           "/start.sh"              11 hours ago        Up 11 hours         8080/tcp                                                                   reportportal_jira_1
0f35b350b4c6        traefik:1.6.6                                             "/traefik --consul..."   11 hours ago        Up 11 hours         80/tcp, 0.0.0.0:8080->8080/tcp                                             reportportal_gateway_1
efda72e9d79b        reportportal/service-rally:4.3.0                          "/start.sh"              11 hours ago        Up 11 hours         8080/tcp                                                                   reportportal_rally_1
90e00a15d2d8        docker.elastic.co/elasticsearch/elasticsearch-oss:6.1.1   "/usr/local/bin/do..."   11 hours ago        Up 2 hours          9200/tcp, 9300/tcp                                                         reportportal_elasticsearch_1
a30e1020ca3a        reportportal/service-ui:4.3.0                             "/service-ui"            11 hours ago        Up 11 hours         8080/tcp                                                                   reportportal_ui_1

anyway, attaching to UAT container does not reveal any errors, i can see the java app keeps running, i can even connect to it's 8080/TCP port:

$ docker exec -it 32381286b788 /bin/sh
# nc localhost 8080
GET / HTTP/1.0

HTTP/1.1 403 
X-Content-Type-Options: nosniff
X-XSS-Protection: 1; mode=block
Cache-Control: no-cache, no-store, max-age=0, must-revalidate
Pragma: no-cache
Expires: 0
X-Frame-Options: DENY
Set-Cookie: JSESSIONID=6A7C04DB1EF15395F6BB2A4F410D3029; Path=/; HttpOnly
Content-Type: application/json;charset=UTF-8
Date: Sat, 03 Nov 2018 10:44:58 GMT
Connection: close

{"timestamp":1541241898347,"status":403,"error":"Forbidden","message":"Access Denied","path":"/"}
#
# ifconfig eth0
eth0      Link encap:Ethernet  HWaddr 02:42:AC:12:00:0B  
          inet addr:172.18.0.11  Bcast:0.0.0.0  Mask:255.255.0.0
          inet6 addr: fe80::42:acff:fe12:b/64 Scope:Link
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
          RX packets:1182508 errors:0 dropped:0 overruns:0 frame:0
          TX packets:1490088 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:0 
          RX bytes:912938526 (870.6 MiB)  TX bytes:1146207072 (1.0 GiB)

TCP connection seems to be okay between tha API and UAT containers as well:

# attaching to API service container
$ docker exec -it 59ca520a4b61 /bin/bash
root@59ca520a4b61:/# curl 172.18.0.11:8080
{"timestamp":1541242060597,"status":403,"error":"Forbidden","message":"Access Denied","path":"/"}root@59ca520a4b61:/#

Not even authentication through UI works, it actually reveal much less info than the direct API request.
The service automatically redirects UI to /404


index_1          | 2018/11/03 10:49:36 "POST http://localhost:8080/uat/sso/oauth/token?grant_type=password&password=my_pass&username=my_user HTTP/1.1" from 172.18.0.4:33176 - 302 0B in 14.03µs
ui_1             | 2018/11/03 10:49:36 "GET http://localhost:8080/404.html HTTP/1.1" from 172.18.0.4:51700 - 304 0B in 80.434µs

the disk space seems not to be an issue:

/dev/mapper/fedora_localhost--live-home  305G  6.6G  283G   3% /home

P.S., restarting the UAT service container helped, so i think this is really the UAT service issue.

I'm able to reproduce the behaviour by shooting down the mongodb service for a while.
After mongodb service is down, i can bombard the API service by requests. If i keep it in this state (mongodb down, keep querying API) for some time (e.g. 5mins), UAT service logs the timeout message:

uat_1            | Caused by: com.mongodb.MongoTimeoutException: Timed out after 30000 ms while waiting for a server that matches ReadPreferenceServerSelector{readPreference=primary}. Client view of cluster state is {type=UNKNOWN, servers=[{address=mongodb:27017, type=UNKNOWN, state=CONNECTING, exception={com.mongodb.MongoSocketException: mongodb}, caused by {java.net.UnknownHostException: mongodb}}]
uat_1            | 	at com.mongodb.connection.BaseCluster.createTimeoutException(BaseCluster.java:377) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	at com.mongodb.connection.BaseCluster.selectServer(BaseCluster.java:104) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	at com.mongodb.binding.ClusterBinding$ClusterBindingConnectionSource.<init>(ClusterBinding.java:75) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	at com.mongodb.binding.ClusterBinding$ClusterBindingConnectionSource.<init>(ClusterBinding.java:71) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	at com.mongodb.binding.ClusterBinding.getReadConnectionSource(ClusterBinding.java:63) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	at com.mongodb.operation.CommandOperationHelper.executeWrappedCommandProtocol(CommandOperationHelper.java:90) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	at com.mongodb.operation.CommandOperationHelper.executeWrappedCommandProtocol(CommandOperationHelper.java:85) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	at com.mongodb.operation.CommandReadOperation.execute(CommandReadOperation.java:55) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	at com.mongodb.Mongo.execute(Mongo.java:836) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	at com.mongodb.Mongo$2.execute(Mongo.java:823) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	at com.mongodb.DB.executeCommand(DB.java:729) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	at com.mongodb.DB.command(DB.java:491) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	at com.mongodb.DB.command(DB.java:507) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	at com.mongodb.DB.command(DB.java:462) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	at org.springframework.data.mongodb.core.MongoTemplate$2.doInDB(MongoTemplate.java:382) ~[spring-data-mongodb-1.10.9.RELEASE.jar:na]
uat_1            | 	at org.springframework.data.mongodb.core.MongoTemplate$2.doInDB(MongoTemplate.java:380) ~[spring-data-mongodb-1.10.9.RELEASE.jar:na]
uat_1            | 	at org.springframework.data.mongodb.core.MongoTemplate.execute(MongoTemplate.java:466) ~[spring-data-mongodb-1.10.9.RELEASE.jar:na]
uat_1            | 	... 116 common frames omitted

and then:

uat_1            | 2018-11-03 11:46:12.512  INFO 1 --- [}-mongodb:27017] org.mongodb.driver.cluster               : Exception in monitor thread while connecting to server mongodb:27017
uat_1            | com.mongodb.MongoSocketException: mongodb
uat_1            | 	at com.mongodb.ServerAddress.getSocketAddress(ServerAddress.java:188) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	at com.mongodb.connection.SocketStreamHelper.initialize(SocketStreamHelper.java:57) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	at com.mongodb.connection.SocketStream.open(SocketStream.java:58) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	at com.mongodb.connection.InternalStreamConnection.open(InternalStreamConnection.java:115) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	at com.mongodb.connection.DefaultServerMonitor$ServerMonitorRunnable.run(DefaultServerMonitor.java:113) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	at java.lang.Thread.run(Thread.java:748) [na:1.8.0_151]
uat_1            | Caused by: java.net.UnknownHostException: mongodb
uat_1            | 	at java.net.InetAddress.getAllByName0(InetAddress.java:1280) ~[na:1.8.0_151]
uat_1            | 	at java.net.InetAddress.getAllByName(InetAddress.java:1192) ~[na:1.8.0_151]
uat_1            | 	at java.net.InetAddress.getAllByName(InetAddress.java:1126) ~[na:1.8.0_151]
uat_1            | 	at java.net.InetAddress.getByName(InetAddress.java:1076) ~[na:1.8.0_151]
uat_1            | 	at com.mongodb.ServerAddress.getSocketAddress(ServerAddress.java:186) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	... 5 common frames omitted

If i start up the mongo service after these messages, the UAT seems to log

uat_1            | 2018-11-03 11:46:22.515  INFO 1 --- [}-mongodb:27017] org.mongodb.driver.connection            : Opened connection [connectionId{localValue:882, serverValue:4}] to mongodb:27017
uat_1            | 2018-11-03 11:46:22.516  INFO 1 --- [}-mongodb:27017] org.mongodb.driver.cluster               : Monitor thread successfully connected to server with description ServerDescription{address=mongodb:27017, type=STANDALONE, state=CONNECTED, ok=true, version=ServerVersion{versionList=[3, 4, 17]}, minWireVersion=0, maxWireVersion=5, maxDocumentSize=16777216, roundTripTimeNanos=248987}

but no longer really works. I'll look more into mongodb service when i get some time, perhaps we reach the connection limit or something

update:
I was able to reproduce this again - after some time of constant API querying and logging to RP, the uat threw the MongoSocketException:

uat_1            | 2018-11-03 17:24:45.580  INFO 1 --- [}-mongodb:27017] org.mongodb.driver.cluster               : Exception in monitor thread while connecting to server mongodb:27017
uat_1            | com.mongodb.MongoSocketException: mongodb: Try again
uat_1            | 	at com.mongodb.ServerAddress.getSocketAddress(ServerAddress.java:188) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	at com.mongodb.connection.SocketStreamHelper.initialize(SocketStreamHelper.java:57) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	at com.mongodb.connection.SocketStream.open(SocketStream.java:58) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	at com.mongodb.connection.InternalStreamConnection.open(InternalStreamConnection.java:115) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	at com.mongodb.connection.DefaultServerMonitor$ServerMonitorRunnable.run(DefaultServerMonitor.java:127) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	at java.lang.Thread.run(Thread.java:748) [na:1.8.0_151]
uat_1            | Caused by: java.net.UnknownHostException: mongodb: Try again
uat_1            | 	at java.net.Inet6AddressImpl.lookupAllHostAddr(Native Method) ~[na:1.8.0_151]
uat_1            | 	at java.net.InetAddress$2.lookupAllHostAddr(InetAddress.java:928) ~[na:1.8.0_151]
uat_1            | 	at java.net.InetAddress.getAddressesFromNameService(InetAddress.java:1323) ~[na:1.8.0_151]
uat_1            | 	at java.net.InetAddress.getAllByName0(InetAddress.java:1276) ~[na:1.8.0_151]
uat_1            | 	at java.net.InetAddress.getAllByName(InetAddress.java:1192) ~[na:1.8.0_151]
uat_1            | 	at java.net.InetAddress.getAllByName(InetAddress.java:1126) ~[na:1.8.0_151]
uat_1            | 	at java.net.InetAddress.getByName(InetAddress.java:1076) ~[na:1.8.0_151]
uat_1            | 	at com.mongodb.ServerAddress.getSocketAddress(ServerAddress.java:186) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	... 5 common frames omitted
uat_1            | 2018-11-03 17:26:09.201  INFO 1 --- [}-mongodb:27017] org.mongodb.driver.cluster               : Exception in monitor thread while connecting to server mongodb:27017
uat_1            | com.mongodb.MongoSocketReadTimeoutException: Timeout while receiving message
uat_1            | 	at com.mongodb.connection.InternalStreamConnection.translateReadException(InternalStreamConnection.java:477) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	at com.mongodb.connection.InternalStreamConnection.receiveMessage(InternalStreamConnection.java:228) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	at com.mongodb.connection.CommandHelper.receiveReply(CommandHelper.java:134) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	at com.mongodb.connection.CommandHelper.receiveCommandResult(CommandHelper.java:121) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	at com.mongodb.connection.CommandHelper.executeCommand(CommandHelper.java:32) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	at com.mongodb.connection.InternalStreamConnectionInitializer.initializeConnectionDescription(InternalStreamConnectionInitializer.java:85) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	at com.mongodb.connection.InternalStreamConnectionInitializer.initialize(InternalStreamConnectionInitializer.java:45) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	at com.mongodb.connection.InternalStreamConnection.open(InternalStreamConnection.java:116) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	at com.mongodb.connection.DefaultServerMonitor$ServerMonitorRunnable.run(DefaultServerMonitor.java:113) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	at java.lang.Thread.run(Thread.java:748) [na:1.8.0_151]
uat_1            | Caused by: java.net.SocketTimeoutException: Read timed out
uat_1            | 	at java.net.SocketInputStream.socketRead0(Native Method) ~[na:1.8.0_151]
uat_1            | 	at java.net.SocketInputStream.socketRead(SocketInputStream.java:116) ~[na:1.8.0_151]
uat_1            | 	at java.net.SocketInputStream.read(SocketInputStream.java:171) ~[na:1.8.0_151]
uat_1            | 	at java.net.SocketInputStream.read(SocketInputStream.java:141) ~[na:1.8.0_151]
uat_1            | 	at com.mongodb.connection.SocketStream.read(SocketStream.java:85) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	at com.mongodb.connection.InternalStreamConnection.receiveResponseBuffers(InternalStreamConnection.java:494) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	at com.mongodb.connection.InternalStreamConnection.receiveMessage(InternalStreamConnection.java:224) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	... 8 common frames omitted
uat_1            | 2018-11-03 17:26:56.383  INFO 1 --- [}-mongodb:27017] org.mongodb.driver.connection            : Opened connection [connectionId{localValue:13, serverValue:45}] to mongodb:27017
uat_1            | 2018-11-03 17:27:08.746  INFO 1 --- [}-mongodb:27017] org.mongodb.driver.cluster               : Monitor thread successfully connected to server with description ServerDescription{address=mongodb:27017, type=STANDALONE, state=CONNECTED, ok=true, version=ServerVersion{versionList=[3, 4, 17]}, minWireVersion=0, maxWireVersion=5, maxDocumentSize=16777216, roundTripTimeNanos=7331798657}
uat_1            | 2018-11-03 17:33:13.368  INFO 1 --- [}-mongodb:27017] org.mongodb.driver.cluster               : Exception in monitor thread while connecting to server mongodb:27017
uat_1            | com.mongodb.MongoSocketReadTimeoutException: Timeout while receiving message
uat_1            | 	at com.mongodb.connection.InternalStreamConnection.translateReadException(InternalStreamConnection.java:477) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	at com.mongodb.connection.InternalStreamConnection.receiveMessage(InternalStreamConnection.java:228) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	at com.mongodb.connection.CommandHelper.receiveReply(CommandHelper.java:134) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	at com.mongodb.connection.CommandHelper.receiveCommandResult(CommandHelper.java:121) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	at com.mongodb.connection.CommandHelper.executeCommand(CommandHelper.java:32) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	at com.mongodb.connection.InternalStreamConnectionInitializer.initializeConnectionDescription(InternalStreamConnectionInitializer.java:85) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	at com.mongodb.connection.InternalStreamConnectionInitializer.initialize(InternalStreamConnectionInitializer.java:45) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	at com.mongodb.connection.InternalStreamConnection.open(InternalStreamConnection.java:116) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	at com.mongodb.connection.DefaultServerMonitor$ServerMonitorRunnable.run(DefaultServerMonitor.java:127) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	at java.lang.Thread.run(Thread.java:748) [na:1.8.0_151]
uat_1            | Caused by: java.net.SocketTimeoutException: Read timed out
uat_1            | 	at java.net.SocketInputStream.socketRead0(Native Method) ~[na:1.8.0_151]
uat_1            | 	at java.net.SocketInputStream.socketRead(SocketInputStream.java:116) ~[na:1.8.0_151]
uat_1            | 	at java.net.SocketInputStream.read(SocketInputStream.java:171) ~[na:1.8.0_151]
uat_1            | 	at java.net.SocketInputStream.read(SocketInputStream.java:141) ~[na:1.8.0_151]
uat_1            | 	at com.mongodb.connection.SocketStream.read(SocketStream.java:85) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	at com.mongodb.connection.InternalStreamConnection.receiveResponseBuffers(InternalStreamConnection.java:494) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	at com.mongodb.connection.InternalStreamConnection.receiveMessage(InternalStreamConnection.java:224) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	... 8 common frames omitted
uat_1            | 2018-11-03 17:34:21.992  INFO 1 --- [}-mongodb:27017] org.mongodb.driver.connection            : Opened connection [connectionId{localValue:15, serverValue:54}] to mongodb:27017
uat_1            | 2018-11-03 17:34:24.530  INFO 1 --- [}-mongodb:27017] org.mongodb.driver.cluster               : Monitor thread successfully connected to server with description ServerDescription{address=mongodb:27017, type=STANDALONE, state=CONNECTED, ok=true, version=ServerVersion{versionList=[3, 4, 17]}, minWireVersion=0, maxWireVersion=5, maxDocumentSize=16777216, roundTripTimeNanos=1515805549}
uat_1            | 2018-11-03 17:41:38.489  INFO 1 --- [}-mongodb:27017] org.mongodb.driver.cluster               : Exception in monitor thread while connecting to server mongodb:27017
uat_1            | com.mongodb.MongoSocketOpenException: Exception opening socket
uat_1            | 	at com.mongodb.connection.SocketStream.open(SocketStream.java:63) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	at com.mongodb.connection.InternalStreamConnection.open(InternalStreamConnection.java:115) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	at com.mongodb.connection.DefaultServerMonitor$ServerMonitorRunnable.run(DefaultServerMonitor.java:127) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	at java.lang.Thread.run(Thread.java:748) [na:1.8.0_151]
uat_1            | Caused by: java.net.ConnectException: Connection refused (Connection refused)
uat_1            | 	at java.net.PlainSocketImpl.socketConnect(Native Method) ~[na:1.8.0_151]
uat_1            | 	at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350) ~[na:1.8.0_151]
uat_1            | 	at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206) ~[na:1.8.0_151]
uat_1            | 	at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188) ~[na:1.8.0_151]
uat_1            | 	at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) ~[na:1.8.0_151]
uat_1            | 	at java.net.Socket.connect(Socket.java:589) ~[na:1.8.0_151]
uat_1            | 	at com.mongodb.connection.SocketStreamHelper.initialize(SocketStreamHelper.java:57) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	at com.mongodb.connection.SocketStream.open(SocketStream.java:58) ~[mongo-java-driver-3.4.3.jar:na]
uat_1            | 	... 3 common frames omitted
uat_1            | 2018-11-03 17:41:48.491  INFO 1 --- [}-mongodb:27017] org.mongodb.driver.connection            : Opened connection [connectionId{localValue:17, serverValue:6}] to mongodb:27017
uat_1            | 2018-11-03 17:41:48.492  INFO 1 --- [}-mongodb:27017] org.mongodb.driver.cluster               : Monitor thread successfully connected to server with description ServerDescription{address=mongodb:27017, type=STANDALONE, state=CONNECTED, ok=true, version=ServerVersion{versionList=[3, 4, 17]}, minWireVersion=0, maxWireVersion=5, maxDocumentSize=16777216, roundTripTimeNanos=184522}

mongodb does not reveal anything special, but these are quite often:

mongodb_1        | 2018-11-03T17:41:22.548+0000 I COMMAND  [ftdc] serverStatus was very slow: { after basic: 97, after asserts: 1011, after backgroundFlushing: 1809, after connections: 1809, after dur: 2912, after extra_info: 3777, after globalLock: 4253, after locks: 5005, after network: 5781, after opLatencies: 6747, after opcounters: 7020, after opcountersRepl: 7020, after repl: 7040, after security: 7040, after storageEngine: 7040, after tcmalloc: 7061, after transportSecurity: 7061, after wiredTiger: 7071, at end: 11743 }

I guess mongodb service is quite busy and slow, but UAT manages to reconnect every time, however it remains stuck. Even after mongodb service restart.

i might be a good catch, but within 3-4 week we plan to release beta version of 5.0
which should be stabilized.

New version have a lot of updated under the hood.
But should be re-tested with this issue again.

@DzmitryHumianiuk thanks for headsup, will test it out then

Resolution: verify under 5.0 version

@rplevka Could you please check it on the latest version 5.0?

I close this issue, if it still reproduces on ver 5.0, please reopen the issue