Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Combining Microcks dev service with Mongo doesn't work in dev mode #30

Closed
edeandrea opened this issue Feb 23, 2024 · 13 comments
Closed
Assignees
Labels
status/wontfix This will not be worked on

Comments

@edeandrea
Copy link
Contributor

edeandrea commented Feb 23, 2024

Describe the bug

When running an app in dev mode that uses both Microcks & Mongodb, dev mode fails to start. I'm not sure if it has to do with Liquibase or not, but the exception is coming from liquibase saying it can't connect to Mongo.

Expected behavior

No response

Actual behavior

No response

How to Reproduce?

  1. Clone https://github.com/quarkusio/quarkus-super-heroes
  2. cd into rest-fights
  3. Run ./mvnw clean quarkus:dev

You should see stack traces like

16:09:27 INFO  [or.mo.dr.client] (Quarkus Main Thread) MongoClient with metadata {"driver": {"name": "mongo-java-driver|sync", "version": "4.11.1"}, "os": {"type": "Darwin", "name": "Mac OS X", "architecture": "aarch64", "version": "14.3.1"}, "platform": "Java/Eclipse Adoptium/17.0.10+7"} created with settings MongoClientSettings{readPreference=primary, writeConcern=WriteConcern{w=null, wTimeout=null ms, journal=null}, retryWrites=true, retryReads=true, readConcern=ReadConcern{level=null}, credential=null, transportSettings=null, streamFactoryFactory=null, commandListeners=[], codecRegistry=ProvidersCodecRegistry{codecProviders=[ValueCodecProvider{}, BsonValueCodecProvider{}, DBRefCodecProvider{}, DBObjectCodecProvider{}, DocumentCodecProvider{}, CollectionCodecProvider{}, IterableCodecProvider{}, MapCodecProvider{}, GeoJsonCodecProvider{}, GridFSFileCodecProvider{}, Jsr310CodecProvider{}, JsonObjectCodecProvider{}, BsonCodecProvider{}, EnumCodecProvider{}, com.mongodb.client.model.mql.ExpressionCodecProvider@5c9f0f1b, com.mongodb.Jep395RecordCodecProvider@fee1cd8, com.mongodb.KotlinCodecProvider@3fbeef8d]}, loggerSettings=LoggerSettings{maxDocumentLength=1000}, clusterSettings={hosts=[mongo-secq6:27017], srvServiceName=mongodb, mode=SINGLE, requiredClusterType=UNKNOWN, requiredReplicaSetName='null', serverSelector='null', clusterListeners='[]', serverSelectionTimeout='30000 ms', localThreshold='15 ms'}, socketSettings=SocketSettings{connectTimeoutMS=10000, readTimeoutMS=0, receiveBufferSize=0, proxySettings=ProxySettings{host=null, port=null, username=null, password=null}}, heartbeatSocketSettings=SocketSettings{connectTimeoutMS=10000, readTimeoutMS=10000, receiveBufferSize=0, proxySettings=ProxySettings{host=null, port=null, username=null, password=null}}, connectionPoolSettings=ConnectionPoolSettings{maxSize=100, minSize=0, maxWaitTimeMS=120000, maxConnectionLifeTimeMS=0, maxConnectionIdleTimeMS=0, maintenanceInitialDelayMS=0, maintenanceFrequencyMS=60000, connectionPoolListeners=[], maxConnecting=2}, serverSettings=ServerSettings{heartbeatFrequencyMS=10000, minHeartbeatFrequencyMS=500, serverListeners='[]', serverMonitorListeners='[]'}, sslSettings=SslSettings{enabled=false, invalidHostNameAllowed=false, context=null}, applicationName='null', compressorList=[], uuidRepresentation=UNSPECIFIED, serverApi=null, autoEncryptionSettings=null, dnsClient=null, inetAddressResolver=null, contextProvider=null}

16:09:27 INFO  [or.mo.dr.cluster] (cluster-ClusterId{value='65d9098794916f7ab4eea6bb', description='null'}-mongo-secq6:27017) Exception in monitor thread while connecting to server mongo-secq6:27017: com.mongodb.MongoSocketException: mongo-secq6: nodename nor servname provided, or not known
        at com.mongodb.ServerAddress.getSocketAddresses(ServerAddress.java:221)
        at com.mongodb.internal.connection.ServerAddressWithResolver.getSocketAddresses(ServerAddressWithResolver.java:68)
        at com.mongodb.internal.connection.SocketStream.initializeSocket(SocketStream.java:100)
        at com.mongodb.internal.connection.SocketStream.open(SocketStream.java:78)
        at com.mongodb.internal.connection.InternalStreamConnection.open(InternalStreamConnection.java:211)
        at com.mongodb.internal.connection.DefaultServerMonitor$ServerMonitorRunnable.lookupServerDescription(DefaultServerMonitor.java:196)
        at com.mongodb.internal.connection.DefaultServerMonitor$ServerMonitorRunnable.run(DefaultServerMonitor.java:156)
        at java.base/java.lang.Thread.run(Thread.java:840)
Caused by: java.net.UnknownHostException: mongo-secq6: nodename nor servname provided, or not known
        at java.base/java.net.Inet6AddressImpl.lookupAllHostAddr(Native Method)
        at java.base/java.net.InetAddress$PlatformNameService.lookupAllHostAddr(InetAddress.java:934)
        at java.base/java.net.InetAddress.getAddressesFromNameService(InetAddress.java:1543)
        at java.base/java.net.InetAddress$NameServiceAddresses.get(InetAddress.java:852)
        at java.base/java.net.InetAddress.getAllByName0(InetAddress.java:1533)
        at java.base/java.net.InetAddress.getAllByName(InetAddress.java:1385)
        at java.base/java.net.InetAddress.getAllByName(InetAddress.java:1306)
        at com.mongodb.ServerAddress.getSocketAddresses(ServerAddress.java:213)
        ... 7 more


16:09:27 INFO  [or.mo.dr.cluster] (Quarkus Main Thread) No server chosen by ReadPreferenceServerSelector{readPreference=primary} from cluster description ClusterDescription{type=UNKNOWN, connectionMode=SINGLE, serverDescriptions=[ServerDescription{address=mongo-secq6:27017, type=UNKNOWN, state=CONNECTING, exception={com.mongodb.MongoSocketException: mongo-secq6: nodename nor servname provided, or not known}, caused by {java.net.UnknownHostException: mongo-secq6: nodename nor servname provided, or not known}}]}. Waiting for 30000 ms before timing out
16:09:28 INFO  [or.mo.dr.cluster] (cluster-ClusterId{value='65d9098794916f7ab4eea6bb', description='null'}-mongo-secq6:27017) Exception in monitor thread while connecting to server mongo-secq6:27017: com.mongodb.MongoSocketException: mongo-secq6
        at com.mongodb.ServerAddress.getSocketAddresses(ServerAddress.java:221)
        at com.mongodb.internal.connection.ServerAddressWithResolver.getSocketAddresses(ServerAddressWithResolver.java:68)
        at com.mongodb.internal.connection.SocketStream.initializeSocket(SocketStream.java:100)
        at com.mongodb.internal.connection.SocketStream.open(SocketStream.java:78)
        at com.mongodb.internal.connection.InternalStreamConnection.open(InternalStreamConnection.java:211)
        at com.mongodb.internal.connection.DefaultServerMonitor$ServerMonitorRunnable.lookupServerDescription(DefaultServerMonitor.java:196)
        at com.mongodb.internal.connection.DefaultServerMonitor$ServerMonitorRunnable.run(DefaultServerMonitor.java:156)
        at java.base/java.lang.Thread.run(Thread.java:840)
Caused by: java.net.UnknownHostException: mongo-secq6
        at java.base/java.net.InetAddress$CachedAddresses.get(InetAddress.java:801)
        at java.base/java.net.InetAddress.getAllByName0(InetAddress.java:1533)
        at java.base/java.net.InetAddress.getAllByName(InetAddress.java:1385)
        at java.base/java.net.InetAddress.getAllByName(InetAddress.java:1306)
        at com.mongodb.ServerAddress.getSocketAddresses(ServerAddress.java:213)
        ... 7 more

16:09:57 INFO  [li.command] (Quarkus Main Thread) Logging exception.
ERROR: Exception Details
ERROR: Exception Primary Class:  MongoTimeoutException
ERROR: Exception Primary Reason: 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=mongo-secq6:27017, type=UNKNOWN, state=CONNECTING, exception={com.mongodb.MongoSocketException: mongo-secq6}, caused by {java.net.UnknownHostException: mongo-secq6}}]
ERROR: Exception Primary Source: MongoDB 0
16:09:57 INFO  [li.command] (Quarkus Main Thread) Command execution complete
16:09:57 ERROR [io.qu.ru.Application] (Quarkus Main Thread) Failed to start application (with profile [dev]): java.lang.RuntimeException: Failed to start quarkus
        at io.quarkus.runner.ApplicationImpl.doStart(Unknown Source)
        at io.quarkus.runtime.Application.start(Application.java:101)
        at io.quarkus.runtime.ApplicationLifecycleManager.run(ApplicationLifecycleManager.java:111)
        at io.quarkus.runtime.Quarkus.run(Quarkus.java:71)
        at io.quarkus.runtime.Quarkus.run(Quarkus.java:44)
        at io.quarkus.runtime.Quarkus.run(Quarkus.java:124)
        at io.quarkus.runner.GeneratedMain.main(Unknown Source)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.base/java.lang.reflect.Method.invoke(Method.java:568)
        at io.quarkus.runner.bootstrap.StartupActionImpl$1.run(StartupActionImpl.java:113)
        at java.base/java.lang.Thread.run(Thread.java:840)
Caused by: java.lang.IllegalStateException: Error starting Liquibase
        at io.quarkus.liquibase.mongodb.runtime.LiquibaseMongodbRecorder.doStartActions(LiquibaseMongodbRecorder.java:73)
        at io.quarkus.deployment.steps.LiquibaseMongodbProcessor$startLiquibase1767457900.deploy_0(Unknown Source)
        at io.quarkus.deployment.steps.LiquibaseMongodbProcessor$startLiquibase1767457900.deploy(Unknown Source)
        ... 13 more
Caused by: liquibase.exception.CommandExecutionException: liquibase.exception.UnexpectedLiquibaseException: liquibase.exception.DatabaseException: Could not query for long
        at liquibase.command.CommandScope.execute(CommandScope.java:253)
        at liquibase.Liquibase.lambda$validate$25(Liquibase.java:1352)
        at liquibase.Scope.lambda$child$0(Scope.java:186)
        at liquibase.Scope.child(Scope.java:195)
        at liquibase.Scope.child(Scope.java:185)
        at liquibase.Scope.child(Scope.java:164)
        at liquibase.Liquibase.runInScope(Liquibase.java:1419)
        at liquibase.Liquibase.validate(Liquibase.java:1347)
        at io.quarkus.liquibase.mongodb.runtime.LiquibaseMongodbRecorder.doStartActions(LiquibaseMongodbRecorder.java:63)
        ... 15 more
Caused by: liquibase.exception.UnexpectedLiquibaseException: liquibase.exception.DatabaseException: Could not query for long
        at liquibase.nosql.changelog.AbstractNoSqlHistoryService.hasDatabaseChangeLogTable(AbstractNoSqlHistoryService.java:145)
        at liquibase.nosql.changelog.AbstractNoSqlHistoryService.init(AbstractNoSqlHistoryService.java:120)
        at liquibase.command.core.helpers.DatabaseChangelogCommandStep.checkLiquibaseTables(DatabaseChangelogCommandStep.java:141)
        at liquibase.command.core.helpers.DatabaseChangelogCommandStep.run(DatabaseChangelogCommandStep.java:91)
        at liquibase.command.CommandScope.execute(CommandScope.java:217)
        ... 23 more
Caused by: liquibase.exception.DatabaseException: Could not query for long
        at liquibase.nosql.executor.NoSqlExecutor.queryForLong(NoSqlExecutor.java:117)
        at liquibase.nosql.executor.NoSqlExecutor.queryForLong(NoSqlExecutor.java:108)
        at liquibase.ext.mongodb.changelog.MongoHistoryService.existsRepository(MongoHistoryService.java:97)
        at liquibase.nosql.changelog.AbstractNoSqlHistoryService.hasDatabaseChangeLogTable(AbstractNoSqlHistoryService.java:143)
        ... 27 more
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=mongo-secq6:27017, type=UNKNOWN, state=CONNECTING, exception={com.mongodb.MongoSocketException: mongo-secq6}, caused by {java.net.UnknownHostException: mongo-secq6}}]
        at com.mongodb.internal.connection.BaseCluster.createTimeoutException(BaseCluster.java:380)
        at com.mongodb.internal.connection.BaseCluster.selectServer(BaseCluster.java:125)
        at com.mongodb.internal.connection.SingleServerCluster.selectServer(SingleServerCluster.java:46)
        at com.mongodb.internal.binding.ClusterBinding.getReadConnectionSource(ClusterBinding.java:116)
        at com.mongodb.client.internal.ClientSessionBinding.getConnectionSource(ClientSessionBinding.java:128)
        at com.mongodb.client.internal.ClientSessionBinding.getReadConnectionSource(ClientSessionBinding.java:92)
        at com.mongodb.internal.operation.SyncOperationHelper.withSuppliedResource(SyncOperationHelper.java:144)
        at com.mongodb.internal.operation.SyncOperationHelper.withSourceAndConnection(SyncOperationHelper.java:125)
        at com.mongodb.internal.operation.SyncOperationHelper.lambda$executeRetryableRead$4(SyncOperationHelper.java:189)
        at com.mongodb.internal.operation.SyncOperationHelper.lambda$decorateReadWithRetries$12(SyncOperationHelper.java:292)
        at com.mongodb.internal.async.function.RetryingSyncSupplier.get(RetryingSyncSupplier.java:67)
        at com.mongodb.internal.operation.SyncOperationHelper.executeRetryableRead(SyncOperationHelper.java:194)
        at com.mongodb.internal.operation.SyncOperationHelper.executeRetryableRead(SyncOperationHelper.java:176)
        at com.mongodb.internal.operation.CommandReadOperation.execute(CommandReadOperation.java:48)
        at com.mongodb.client.internal.MongoClientDelegate$DelegateOperationExecutor.execute(MongoClientDelegate.java:153)
        at com.mongodb.client.internal.MongoDatabaseImpl.executeCommand(MongoDatabaseImpl.java:196)
        at com.mongodb.client.internal.MongoDatabaseImpl.runCommand(MongoDatabaseImpl.java:165)
        at com.mongodb.client.internal.MongoDatabaseImpl.runCommand(MongoDatabaseImpl.java:160)
        at com.mongodb.client.internal.MongoDatabaseImpl.runCommand(MongoDatabaseImpl.java:150)
        at liquibase.ext.mongodb.statement.AbstractRunCommandStatement.run(AbstractRunCommandStatement.java:59)
        at liquibase.ext.mongodb.statement.AbstractRunCommandStatement.run(AbstractRunCommandStatement.java:55)
        at liquibase.ext.mongodb.statement.ListCollectionNamesStatement.queryForList(ListCollectionNamesStatement.java:79)
        at liquibase.ext.mongodb.statement.CountCollectionByNameStatement.queryForLong(CountCollectionByNameStatement.java:44)
        at liquibase.ext.mongodb.statement.CountCollectionByNameStatement.queryForLong(CountCollectionByNameStatement.java:33)
        at liquibase.nosql.executor.NoSqlExecutor.queryForLong(NoSqlExecutor.java:115)
        ... 30 more


16:09:58 INFO  [io.qu.de.de.IsolatedDevModeMain] (main) Attempting to start live reload endpoint to recover from previous Quarkus startup failure

Microcks version or git rev

0.2.2

Install method (docker-compose, helm chart, operator, docker-desktop extension,...)

No response

Additional information

No response

@lbroudoux lbroudoux self-assigned this Mar 5, 2024
@lbroudoux
Copy link
Member

Thanks for raising this issue. I succeeded in reproducing it, and I am now having a look at it.

@lbroudoux
Copy link
Member

lbroudoux commented Mar 5, 2024

We've got this exception because Microcks is now forcing the usage of a shared network for its containers and those related to brokers (eg. Kafka). This is indeed mandatory if we want to be able to have both:

  • possible connection between different dev services containers,
  • possible connection between the application (on localhost) and dev services containers.

Kafka dev service manages this well by adding an extra listener when a shared network is detected. So it presents 2 possibilities for connection in the bootstrap servers property: something like PLAINTEXT://kafka-3g7kd:9092,OUTSIDE://localhost:60790 that allows connecting from both origins.

MongoDB dev services (and I suppose most other dev service related to database) don't seem to have this behaviour and automatically bind the container host to the shared network only, and generate a new host name like mongo-3n9d6 or something.... Obviously this one cannot be resolved from the application and lead to the error above.

TBH I don't know what to do at the moment

@edeandrea
Copy link
Contributor Author

Probably related to this too: quarkusio/quarkus#23916

What was the change that forced a shared network and why was that needed?

@lbroudoux
Copy link
Member

lbroudoux commented Mar 5, 2024

Yes, I think it's related to the same issue. useSharedNetwork seems to be forced when running integration tests.

Forcing the shared network was mandatory as we now may start different containers.

The first microcks container is mandatory and always started. Then, depending on the project configuration (AsyncAPI and Kafka present? Postman artifacts?) we may need to start additional microcks-postman and microcks-async-minion containers.

The problem is that microcks-async-minion must be started after the Kafka dev service (obvious) and that microcks container should be able to reach microcks-async-minion. We need a well-know port and hostname as this setup is done at container startup. So ... the only (easy- way of doing that is to use network aliases and fixed ports within a network ... the shared network!

So now, at startup, Microcks forces the creation of the shared network and all the container are registered within this one with well-know aliases and ports. That wasn't an issue for Kafka but seems to be one for database.

Check quarkusio/quarkus#38398 (reply in thread) for more details on this.

@lbroudoux
Copy link
Member

Have started/continued a discussion with the Quarkus team here: quarkusio/quarkus#38398 (comment)

@lbroudoux
Copy link
Member

Hey @edeandrea!

I made some changes in Quarkus and suggested enhancement here: quarkusio/quarkus#38398 (reply in thread)

I hope this will help solve this issue.

@edeandrea
Copy link
Contributor Author

yay! I've been following that thread...

@lbroudoux
Copy link
Member

lbroudoux commented Apr 4, 2024

Hey @edeandrea,

I've taken some steps forward to make this work. We've changed how the data source-related DevServices are joining the shared network, having them join it only when running integration test with the containerized app - that was the original behavior and intent of shared-network.

So, we're back to the initial situation where:

  • When running mvn quarkus:dev, your DB will be accessible using localhost:<port> even if Microcks is using a shared network for its own purposes
  • When running mvn test, your DB will be accessible using localhost:<port> even if Microcks is using a shared network for its own purposes
  • When running mvn verify -Dquarkus.container-image.build=true, your DB will be run on the shared network with mongo-<random>:<port> on the same shared network that all other DevServices

That said, I've got errors when I run mvn verify -Dquarkus.container-image.build=true. The tests are failing because at some points it seems to get fallback values instead of expected ones:

field/property 'villain.name' differ:
- actual value  : "Fallback villain"
- expected value: "Super Chocolatine"

and also

[ERROR] io.quarkus.sample.superheroes.fight.rest.FightResourceIT.helloVillainsFallback -- Time elapsed: 0.006 s <<< FAILURE!
com.github.tomakehurst.wiremock.client.VerificationException: 
Expected at least one request matching: {
  "url" : "/api/villains/hello",
  "method" : "GET",
  "headers" : {
    "Accept" : {
      "contains" : "text/plain"
    }
  }
}
Requests received: [ ]
	at com.github.tomakehurst.wiremock.client.WireMock.verificationExceptionForNearMisses(WireMock.java:758)
	at com.github.tomakehurst.wiremock.client.WireMock.verifyThat(WireMock.java:745)
	at com.github.tomakehurst.wiremock.client.WireMock.verifyThat(WireMock.java:725)
	at com.github.tomakehurst.wiremock.WireMockServer.verify(WireMockServer.java:299)
	at io.quarkus.sample.superheroes.fight.rest.FightResourceIT.helloVillainsFallback(FightResourceIT.java:1021)
	at java.base/java.lang.reflect.Method.invoke(Method.java:568)
	at java.base/java.util.ArrayList.forEach(ArrayList.java:1511)
	at java.base/java.util.ArrayList.forEach(ArrayList.java:1511)

I reverted my changes - thinking I introduced a regression - but I've got the same behaviour when getting back to the previous Quarkus 3.8.2. Is it a normal thing?

Thanks,

@edeandrea
Copy link
Contributor Author

No it's definitely not normal :)

I'm without power and Internet at the moment (freak spring snowstorm here in the northeast), but once im back online I can take a look.

@edeandrea
Copy link
Contributor Author

OK so wait a second - without any of your new changes, running ./mvnw verify -Dquarkus.container-image.build=true on rest-fights would never have worked because the integration test would not be able to communicate with the Apicurio registry.

The IT uses the KafkaCompanion to talk with the kafka broker, and because we're using avro, the companion also needs to talk to Apicurio. quarkusio/quarkus#23916 describes this issue in more detail.

@lbroudoux
Copy link
Member

This will be solved once this PR quarkusio/quarkus#39899 is merged and released in Quarkus.

@edeandrea
Copy link
Contributor Author

@lbroudoux I can confirm that this issue has been resolved with the release of Quarkus 3.10.0 and quarkus-microcks version 0.2.4.

See quarkusio/quarkus-super-heroes@3606248

@lbroudoux
Copy link
Member

🎉 Thanks for the confirmation @edeandrea! I think we can now close this issue so.

@lbroudoux lbroudoux added the status/wontfix This will not be worked on label Apr 30, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
status/wontfix This will not be worked on
Projects
None yet
Development

No branches or pull requests

2 participants