3

Even run one test you need more than 1 minute:

  • Startup for embed Mongo ~1 minute
  • test execution ~3-8 seconds

I can't understand what is the reason for such behaviour?
Following is snipped from console:

2018-12-13 13:14:43.214  INFO 12277 --- [           main] c.j.s.embedmongo.EmbeddedMongoBuilder    : Initializing embedded MongoDB instance
2018-12-13 13:14:43.293  INFO 12277 --- [           main] d.f.embed.process.store.Downloader       : Extract /Users/nazar/.embedmongo/osx/mongodb-osx-ssl-x86_64-3.6.5.tgz : starting...
2018-12-13 13:14:44.287  INFO 12277 --- [           main] d.f.embed.process.store.Downloader       : Extract /Users/nazar/.embedmongo/osx/mongodb-osx-ssl-x86_64-3.6.5.tgz : extract mongodb-osx-x86_64-3.6.5/bin/mongod
2018-12-13 13:14:44.288  INFO 12277 --- [           main] d.f.embed.process.store.Downloader       : Extract /Users/nazar/.embedmongo/osx/mongodb-osx-ssl-x86_64-3.6.5.tgz : nothing left
2018-12-13 13:14:44.288  INFO 12277 --- [           main] d.f.embed.process.store.Downloader       : Extract /Users/nazar/.embedmongo/osx/mongodb-osx-ssl-x86_64-3.6.5.tgz : finished
2018-12-13 13:14:44.289  INFO 12277 --- [           main] c.j.s.embedmongo.EmbeddedMongoBuilder    : Starting embedded MongoDB instance
2018-12-13 13:14:45.467  INFO 12277 --- [           main] d.f.embed.mongo.MongodExecutable         : start de.flapdoodle.embed.mongo.config.MongodConfigBuilder$ImmutableMongodConfig@55fee662
2018-12-13 13:14:45.871  INFO 12277 --- [           main] org.mongodb.driver.cluster               : Cluster created with settings {hosts=[localhost:50770], mode=SINGLE, requiredClusterType=UNKNOWN, serverSelectionTimeout='30000 ms', maxWaitQueueSize=500}
2018-12-13 13:14:45.985  INFO 12277 --- [localhost:50770] org.mongodb.driver.connection            : Opened connection [connectionId{localValue:1, serverValue:1}] to localhost:50770
2018-12-13 13:14:45.990  INFO 12277 --- [localhost:50770] org.mongodb.driver.cluster               : Monitor thread successfully connected to server with description ServerDescription{address=localhost:50770, type=STANDALONE, state=CONNECTED, ok=true, version=ServerVersion{versionList=[3, 6, 5]}, minWireVersion=0, maxWireVersion=6, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=4065087}
2018-12-13 13:14:46.627  WARN 12277 --- [           main] c.t.p.p.configuration.BugsnagConfig      : Bugsnag apikey not set, not using it
2018-12-13 13:14:46.702  INFO 12277 --- [           main] c.t.p.p.c.AsyncConfigurationTest         : Creating sync task executor for tests
2018-12-13 13:15:38.019  INFO 12277 --- [       Thread-7] o.s.b.a.mongo.embedded.EmbeddedMongo     : note: noprealloc may hurt performance in many applications
2018-12-13 13:15:38.057  INFO 12277 --- [       Thread-7] o.s.b.a.mongo.embedded.EmbeddedMongo     : 2018-12-13T13:15:38.056+0200 I CONTROL  [initandlisten] MongoDB starting : pid=12460 port=50789 dbpath=/var/folders/95/6cdccp1s629gtfwm5tjb63gr0000gp/T/embedmongo-db-8535bf9e-fdc6-44f3-88c8-4bc77dd60bb3 64-bit host=sdos-MacBook-Pro.local
2018-12-13 13:15:38.057  INFO 12277 --- [       Thread-7] o.s.b.a.mongo.embedded.EmbeddedMongo     : 2018-12-13T13:15:38.057+0200 I CONTROL  [initandlisten] db version v3.5.5
2018-12-13 13:15:38.058  INFO 12277 --- [       Thread-7] o.s.b.a.mongo.embedded.EmbeddedMongo     : 2018-12-13T13:15:38.057+0200 I CONTROL  [initandlisten] git version: 98515c812b6fa893613f063dae568ff8319cbfbd
2018-12-13 13:15:38.058  INFO 12277 --- [       Thread-7] o.s.b.a.mongo.embedded.EmbeddedMongo     : 2018-12-13T13:15:38.057+0200 I CONTROL  [initandlisten] allocator: system
2018-12-13 13:15:38.058  INFO 12277 --- [       Thread-7] o.s.b.a.mongo.embedded.EmbeddedMongo     : 2018-12-13T13:15:38.057+0200 I CONTROL  [initandlisten] modules: none
2018-12-13 13:15:38.058  INFO 12277 --- [       Thread-7] o.s.b.a.mongo.embedded.EmbeddedMongo     : 2018-12-13T13:15:38.057+0200 I CONTROL  [initandlisten] build environment:
2018-12-13 13:15:38.058  INFO 12277 --- [       Thread-7] o.s.b.a.mongo.embedded.EmbeddedMongo     : 2018-12-13T13:15:38.057+0200 I CONTROL  [initandlisten]     distarch: x86_64
2018-12-13 13:15:38.058  INFO 12277 --- [       Thread-7] o.s.b.a.mongo.embedded.EmbeddedMongo     : 2018-12-13T13:15:38.057+0200 I CONTROL  [initandlisten]     target_arch: x86_64
2018-12-13 13:15:38.058  INFO 12277 --- [       Thread-7] o.s.b.a.mongo.embedded.EmbeddedMongo     : 2018-12-13T13:15:38.057+0200 I CONTROL  [initandlisten] options: { net: { bindIp: "127.0.0.1", http: { enabled: false }, port: 50789 }, security: { authorization: "disabled" }, storage: { dbPath: "/var/folders/95/6cdccp1s629gtfwm5tjb63gr0000gp/T/embedmongo-db-8535bf9e-fdc6-44f3-88c8-4bc77dd60bb3", journal: { enabled: false }, mmapv1: { preallocDataFiles: false, smallFiles: true }, syncPeriodSecs: 0.0 } }

Here is: full console log

It stucks the most after the line:

c.t.p.p.c.AsyncConfigurationTest: Creating sync task executor for tests

Here is a snippet from pom file:

<parent>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter-parent</artifactId>
    <version>2.1.0.RELEASE</version>
    <relativePath/> <!-- lookup parent from repository -->
</parent>
<dependencies>
    <dependency>
        <groupId>org.springframework.boot</groupId>
        <artifactId>spring-boot-starter-data-mongodb</artifactId>
    </dependency>
    <dependency>
        <groupId>de.flapdoodle.embed</groupId>
        <artifactId>de.flapdoodle.embed.mongo</artifactId>
        <version>2.1.1</version>
        <scope>test</scope>
    </dependency>
    <dependency>
        <groupId>cz.jirutka.spring</groupId>
        <artifactId>embedmongo-spring</artifactId>
        <version>1.3.1</version>
        <scope>test</scope>
    </dependency>
    <dependency>
        <groupId>org.springframework.boot</groupId>
        <artifactId>spring-boot-starter-test</artifactId>
        <scope>test</scope>
    </dependency>

No additional plugins, only spring-boot-maven-plugin.
Also, no additional configuration at application.yml for tests.

Mongo configuration is next:

@Configuration
public class MongoConfig {

    private static final String MONGO_DB_URL = "localhost";
    private static final String MONGO_DB_NAME = "embeded_db";

    @Bean
    public MongoTemplate mongoTemplate() throws IOException {
        EmbeddedMongoFactoryBean mongo = new EmbeddedMongoFactoryBean();
        mongo.setBindIp(MONGO_DB_URL);
        MongoClient mongoClient = mongo.getObject();
        return new MongoTemplate(mongoClient, MONGO_DB_NAME);
    }
}

Task execuotor configuration:

@Slf4j
@Configuration
@Profile("test")
public class AsyncConfigurationTest {

    @Bean
    @Primary
    public TaskExecutor taskExecutor() {
        log.info("Creating sync task executor for tests");
        return new SyncTaskExecutor();
    }
}

Test looks next:

@Slf4j
@SpringBootTest
@ActiveProfiles("test")
@RunWith(SpringRunner.class)
public class ServiceTest extends BaseDataServiceTest {

@Value("classpath:enter/enter_file.pdf")
private Resource enterPdf;
@Value("classpath:enter/expected.json")
private Resource enterExpectedJson;

@Test
public void testEnterDemoDocument() {
    testHelper(enterPdf, enterExpectedJson);
}

Everything works fine. However, the speed is very slow for now.
How to investigate what is a bottleneck for it?

What could be the reason for such slow startup?

catch23
  • 17,519
  • 42
  • 144
  • 217
  • You have 2 instances of embedded mongo why? Remove the `embedmongo-spring` leave only the flapdoodle one. Remove your `MongoConfig` as Spring Boot has out-of-the-box support for flapdoodle and try again. Also what is your `BaseDataServiceTest` doing. – M. Deinum Dec 13 '18 at 11:57
  • @M.Deinum unexpectedly it makes test execution much faster ~12 seconds. Could you explain more what it exactly does? – catch23 Dec 13 '18 at 12:00
  • Actually I have no idea but the `embedmongo-spring` library hasn't been touched in about 3 to 4 years (judging by the GitHub repo) whereas the flapdoodle one has been touch 4 days ago. Next to that Spring Boot has out-of-the-box support for this so no need to wrap something else in there. The main concern was remove clutter you don't need and start from there. – M. Deinum Dec 13 '18 at 12:06

2 Answers2

4

Spring Boot has out-of-the-box support for embedded MongoDB. Also the embedmongo-spring seems dated as it hasn't been touched in 3 years.

Use the out-of-the-box support for embedded MongoDB instead of trying to wrap something else around it.

NOTE: You could also remove the <version> from the flapdoodle dependency as Spring Boot has dependency management for it as well.

<dependency>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter-data-mongodb</artifactId>
</dependency>
<dependency>
    <groupId>de.flapdoodle.embed</groupId>
    <artifactId>de.flapdoodle.embed.mongo</artifactId>
    <scope>test</scope>
</dependency>
<dependency>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter-test</artifactId>
    <scope>test</scope>
</dependency>

These dependencies should be all you need.

M. Deinum
  • 115,695
  • 22
  • 220
  • 224
0

I had exactly the same issue, but I'm not using Spring Boot. I found out that the issue in my case is this line (embedded mongo uses that):

        InetAddress ret = InetAddress.getLocalHost();

And this is the fix InetAddress.getLocalHost() slow to run (30+ seconds)

Andrii Karaivanskyi
  • 1,942
  • 3
  • 19
  • 23