mongodbspring-bootkotlinspring-data-mongodb-reactivemongock

Mongock does not run changeunit in kotlin project


I have Java + maven project - https://github.com/petersuchy/mongock-test-java based on Mongock reactive example (https://github.com/mongock/mongock-examples/tree/master/mongodb/springboot-reactive)

And everything works well.

I tried to migrate that project into Kotlin + gradle - https://github.com/petersuchy/mongock-test-kotlin

And I am able to run it. But my ChangeUnit is ignored. Mongock is set up properly beacause in the end I have 2 collections created - mongockLock and mongockChangeLog.

I tried to get rid of @Value annotations in MongockConfig and MongoClientConfig, but there was no change in behaviour.

Can you please point me why is this happening? I think it can be something with these Reflections becasue it is only difference in logs.

Kotlin:

2023-02-12T00:49:58.455+01:00  INFO 80854 --- [           main] i.m.r.c.e.system.SystemUpdateExecutor    : Mongock has finished the system update execution
2023-02-12T00:49:58.457+01:00  INFO 80854 --- [           main] org.reflections.Reflections              : Reflections took 0 ms to scan 0 urls, producing 0 keys and 0 values
2023-02-12T00:49:58.458+01:00  INFO 80854 --- [           main] org.reflections.Reflections              : Reflections took 1 ms to scan 0 urls, producing 0 keys and 0 values
2023-02-12T00:49:58.458+01:00  INFO 80854 --- [           main] i.m.r.c.e.o.migrate.MigrateExecutorBase  : Mongock skipping the data migration. There is no change set item.

Java:

2023-02-12T00:29:48.064+01:00  INFO 78548 --- [           main] i.m.r.c.e.system.SystemUpdateExecutor    : Mongock has finished the system update execution
2023-02-12T00:29:48.072+01:00  INFO 78548 --- [           main] org.reflections.Reflections              : Reflections took 6 ms to scan 1 urls, producing 1 keys and 2 values
2023-02-12T00:29:48.075+01:00  INFO 78548 --- [           main] org.reflections.Reflections              : Reflections took 3 ms to scan 1 urls, producing 1 keys and 2 values
2023-02-12T00:29:48.081+01:00  INFO 78548 --- [           main] i.m.driver.core.lock.LockManagerDefault  : Mongock trying to acquire the lock

Here is the full log from Kotlin project

2023-02-12T00:49:55.863+01:00  INFO 80854 --- [           main] c.e.m.MongockTestKotlinApplicationKt     : No active profile set, falling back to 1 default profile: "default"
2023-02-12T00:49:56.764+01:00  INFO 80854 --- [           main] .s.d.r.c.RepositoryConfigurationDelegate : Bootstrapping Spring Data Reactive MongoDB repositories in DEFAULT mode.
2023-02-12T00:49:57.019+01:00  INFO 80854 --- [           main] .s.d.r.c.RepositoryConfigurationDelegate : Finished Spring Data repository scanning in 246 ms. Found 1 Reactive MongoDB repository interfaces.
2023-02-12T00:49:57.919+01:00  INFO 80854 --- [           main] org.mongodb.driver.client                : MongoClient with metadata {"driver": {"name": "mongo-java-driver|reactive-streams|spring-boot", "version": "4.8.2"}, "os": {"type": "Linux", "name": "Linux", "architecture": "amd64", "version": "5.15.0-60-generic"}, "platform": "Java/Private Build/17.0.5+8-Ubuntu-2ubuntu122.04"} 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, streamFactoryFactory=NettyStreamFactoryFactory{eventLoopGroup=io.netty.channel.nio.NioEventLoopGroup@631cb129, socketChannelClass=class io.netty.channel.socket.nio.NioSocketChannel, allocator=PooledByteBufAllocator(directByDefault: true), sslContext=null}, commandListeners=[], codecRegistry=ProvidersCodecRegistry{codecProviders=[ValueCodecProvider{}, BsonValueCodecProvider{}, DBRefCodecProvider{}, DBObjectCodecProvider{}, DocumentCodecProvider{}, CollectionCodecProvider{}, IterableCodecProvider{}, MapCodecProvider{}, GeoJsonCodecProvider{}, GridFSFileCodecProvider{}, Jsr310CodecProvider{}, JsonObjectCodecProvider{}, BsonCodecProvider{}, EnumCodecProvider{}, com.mongodb.Jep395RecordCodecProvider@3d20e575]}, clusterSettings={hosts=[localhost:27017], srvServiceName=mongodb, mode=SINGLE, requiredClusterType=UNKNOWN, requiredReplicaSetName='null', serverSelector='null', clusterListeners='[]', serverSelectionTimeout='30000 ms', localThreshold='30000 ms'}, socketSettings=SocketSettings{connectTimeoutMS=10000, readTimeoutMS=0, receiveBufferSize=0, sendBufferSize=0}, heartbeatSocketSettings=SocketSettings{connectTimeoutMS=10000, readTimeoutMS=10000, receiveBufferSize=0, sendBufferSize=0}, 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=JAVA_LEGACY, serverApi=null, autoEncryptionSettings=null, contextProvider=null}
2023-02-12T00:49:57.968+01:00  INFO 80854 --- [           main] i.m.r.core.builder.RunnerBuilderBase     : Mongock runner COMMUNITY version[5.2.2]
2023-02-12T00:49:57.970+01:00  INFO 80854 --- [           main] i.m.r.core.builder.RunnerBuilderBase     : Running Mongock with NO metadata
2023-02-12T00:49:58.034+01:00  INFO 80854 --- [localhost:27017] org.mongodb.driver.cluster               : Monitor thread successfully connected to server with description ServerDescription{address=localhost:27017, type=REPLICA_SET_PRIMARY, state=CONNECTED, ok=true, minWireVersion=0, maxWireVersion=17, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=62515465, setName='myReplicaSet', canonicalAddress=mongo1:27017, hosts=[mongo3:27017, mongo2:27017, mongo1:27017], passives=[], arbiters=[], primary='mongo1:27017', tagSet=TagSet{[]}, electionId=7fffffff0000000000000002, setVersion=1, topologyVersion=TopologyVersion{processId=63e7c5a7d11b71e048698dab, counter=6}, lastWriteDate=Sun Feb 12 00:49:53 CET 2023, lastUpdateTimeNanos=45870970528894}
2023-02-12T00:49:58.336+01:00  INFO 80854 --- [           main] org.reflections.Reflections              : Reflections took 33 ms to scan 1 urls, producing 2 keys and 2 values
2023-02-12T00:49:58.343+01:00  INFO 80854 --- [           main] org.reflections.Reflections              : Reflections took 2 ms to scan 1 urls, producing 2 keys and 2 values
2023-02-12T00:49:58.367+01:00  INFO 80854 --- [           main] i.m.driver.core.lock.LockManagerDefault  : Mongock trying to acquire the lock
2023-02-12T00:49:58.400+01:00  INFO 80854 --- [           main] i.m.driver.core.lock.LockManagerDefault  : Mongock acquired the lock until: Sun Feb 12 00:50:58 CET 2023
2023-02-12T00:49:58.401+01:00  INFO 80854 --- [       Thread-1] i.m.driver.core.lock.LockManagerDefault  : Starting mongock lock daemon...
2023-02-12T00:49:58.404+01:00  INFO 80854 --- [           main] i.m.r.c.e.system.SystemUpdateExecutor    : Mongock starting the system update execution id[2023-02-12T00:49:57.955733372-712]...
2023-02-12T00:49:58.408+01:00  INFO 80854 --- [           main] i.m.r.c.executor.ChangeLogRuntimeImpl    : method[io.mongock.runner.core.executor.system.changes.SystemChangeUnit00001] with arguments: []
2023-02-12T00:49:58.411+01:00  INFO 80854 --- [           main] i.m.r.c.executor.ChangeLogRuntimeImpl    : method[beforeExecution] with arguments: [io.mongock.driver.mongodb.reactive.repository.MongoReactiveChangeEntryRepository]
2023-02-12T00:49:58.413+01:00  INFO 80854 --- [           main] i.m.r.core.executor.ChangeExecutorBase   : APPLIED - {"id"="system-change-00001_before", "type"="before-execution", "author"="mongock", "class"="SystemChangeUnit00001", "method"="beforeExecution"}
2023-02-12T00:49:58.425+01:00  INFO 80854 --- [           main] i.m.r.c.executor.ChangeLogRuntimeImpl    : method[execution] with arguments: [io.mongock.driver.mongodb.reactive.repository.MongoReactiveChangeEntryRepository]
2023-02-12T00:49:58.429+01:00  INFO 80854 --- [           main] i.m.r.core.executor.ChangeExecutorBase   : APPLIED - {"id"="system-change-00001", "type"="execution", "author"="mongock", "class"="SystemChangeUnit00001", "method"="execution"}
2023-02-12T00:49:58.447+01:00  INFO 80854 --- [           main] i.m.driver.core.lock.LockManagerDefault  : Mongock waiting to release the lock
2023-02-12T00:49:58.447+01:00  INFO 80854 --- [           main] i.m.driver.core.lock.LockManagerDefault  : Mongock releasing the lock
2023-02-12T00:49:58.455+01:00  INFO 80854 --- [           main] i.m.driver.core.lock.LockManagerDefault  : Mongock released the lock
2023-02-12T00:49:58.455+01:00  INFO 80854 --- [           main] i.m.r.c.e.system.SystemUpdateExecutor    : Mongock has finished the system update execution
2023-02-12T00:49:58.457+01:00  INFO 80854 --- [           main] org.reflections.Reflections              : Reflections took 0 ms to scan 0 urls, producing 0 keys and 0 values
2023-02-12T00:49:58.458+01:00  INFO 80854 --- [           main] org.reflections.Reflections              : Reflections took 1 ms to scan 0 urls, producing 0 keys and 0 values
2023-02-12T00:49:58.458+01:00  INFO 80854 --- [           main] i.m.r.c.e.o.migrate.MigrateExecutorBase  : Mongock skipping the data migration. There is no change set item.
2023-02-12T00:49:58.458+01:00  INFO 80854 --- [           main] i.m.r.c.e.o.migrate.MigrateExecutorBase  : Mongock has finished
2023-02-12T00:49:59.190+01:00  INFO 80854 --- [           main] o.s.b.web.embedded.netty.NettyWebServer  : Netty started on port 8080
2023-02-12T00:49:59.201+01:00  INFO 80854 --- [           main] c.e.m.MongockTestKotlinApplicationKt     : Started MongockTestKotlinApplicationKt in 4.086 seconds (process running for 4.773)

Solution

  • The problem is in your application.yam. The migration-scan-package name is wrong. That's the reason Mongock doesn't find any ChangeUnit