[Bug]: Timed out waiting for log output matching '.*DATABASE IS READY TO USE!.*\s'

[yongchuncao]

Module

Oracle-XE

Testcontainers version

1.17.5

Using the latest Testcontainers version?

Yes

Host OS

Windows

Host Arch

x64

Docker version

4.14.0

What happened?

Execution log:

2022-11-15 14:03:18,559 [main] [-] INFO com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Starting...
2022-11-15 14:03:19,315 [main] [-] INFO org.testcontainers.utility.ImageNameSubstitutor - Image name substitution will be performed by: DefaultImageNameSubstitutor (composite of 'ConfigurationFileImageNameSubstitutor' and 'PrefixingImageNameSubstitutor')
2022-11-15 14:03:19,387 [main] [-] INFO org.testcontainers.dockerclient.DockerClientProviderStrategy - Loaded org.testcontainers.dockerclient.NpipeSocketClientProviderStrategy from ~/.testcontainers.properties, will try it first
2022-11-15 14:03:20,863 [main] [-] INFO org.testcontainers.dockerclient.DockerClientProviderStrategy - Found Docker environment with local Npipe socket (npipe:////./pipe/docker_engine)
2022-11-15 14:03:20,866 [main] [-] INFO org.testcontainers.DockerClientFactory - Docker host IP address is localhost
2022-11-15 14:03:20,895 [main] [-] INFO org.testcontainers.DockerClientFactory - Connected to docker: 
  Server Version: 20.10.21
  API Version: 1.41
  Operating System: Docker Desktop
  Total Memory: 2980 MB
2022-11-15 14:03:20,940 [main] [-] INFO 🐳 [testcontainers/ryuk:0.3.4] - Creating container for image: testcontainers/ryuk:0.3.4
2022-11-15 14:03:23,300 [main] [-] INFO org.testcontainers.utility.RegistryAuthLocator - Credential helper/store (docker-credential-desktop) does not have credentials for https://index.docker.io/v1/
2022-11-15 14:03:25,293 [main] [-] INFO 🐳 [testcontainers/ryuk:0.3.4] - Container testcontainers/ryuk:0.3.4 is starting: 9ceed79fdfc7f14aad960957a8baac74e00be7f5a18864589cd9c55c0c1b3aed
2022-11-15 14:03:28,644 [main] [-] INFO 🐳 [testcontainers/ryuk:0.3.4] - Container testcontainers/ryuk:0.3.4 started in PT7.727S
2022-11-15 14:03:28,678 [main] [-] INFO org.testcontainers.utility.RyukResourceReaper - Ryuk started - will monitor and terminate Testcontainers containers on JVM exit
2022-11-15 14:03:28,678 [main] [-] INFO org.testcontainers.DockerClientFactory - Checking the system...
2022-11-15 14:03:28,680 [main] [-] INFO org.testcontainers.DockerClientFactory - ✔︎ Docker server version should be at least 1.6.0
2022-11-15 14:03:28,708 [main] [-] INFO 🐳 [gvenzl/oracle-xe:18.4.0-slim] - Pulling docker image: gvenzl/oracle-xe:18.4.0-slim. Please be patient; this may take some time but only needs to be done once.
2022-11-15 14:03:31,513 [docker-java-stream--620503386] [-] INFO 🐳 [gvenzl/oracle-xe:18.4.0-slim] - Starting to pull image
2022-11-15 14:03:31,565 [docker-java-stream--620503386] [-] INFO 🐳 [gvenzl/oracle-xe:18.4.0-slim] - Pulling image layers:  0 pending,  0 downloaded,  0 extracted, (0 bytes/0 bytes)
2022-11-15 14:03:31,594 [main] [-] INFO 🐳 [gvenzl/oracle-xe:18.4.0-slim] - Creating container for image: gvenzl/oracle-xe:18.4.0-slim
2022-11-15 14:03:32,072 [main] [-] INFO 🐳 [gvenzl/oracle-xe:18.4.0-slim] - Container gvenzl/oracle-xe:18.4.0-slim is starting: 3e76a299c6e2757cf77356b3fb8be627907e22286ac79eda9311448d2e65623a
2022-11-15 14:07:33,763 [main] [-] ERROR 🐳 [gvenzl/oracle-xe:18.4.0-slim] - Could not start container
org.testcontainers.containers.ContainerLaunchException: Timed out waiting for log output matching '.*DATABASE IS READY TO USE!.*\s'
	at org.testcontainers.containers.wait.strategy.LogMessageWaitStrategy.waitUntilReady(LogMessageWaitStrategy.java:47)
	at org.testcontainers.containers.wait.strategy.AbstractWaitStrategy.waitUntilReady(AbstractWaitStrategy.java:52)
	at org.testcontainers.containers.OracleContainer.waitUntilContainerStarted(OracleContainer.java:95)
	at org.testcontainers.containers.GenericContainer.tryStart(GenericContainer.java:485)
	at org.testcontainers.containers.GenericContainer.lambda$doStart$0(GenericContainer.java:344)
	at org.rnorth.ducttape.unreliables.Unreliables.retryUntilSuccess(Unreliables.java:81)
	at org.testcontainers.containers.GenericContainer.doStart(GenericContainer.java:334)
	at org.testcontainers.containers.GenericContainer.start(GenericContainer.java:322)
	at org.testcontainers.jdbc.ContainerDatabaseDriver.connect(ContainerDatabaseDriver.java:124)
	at com.zaxxer.hikari.util.DriverDataSource.getConnection(DriverDataSource.java:138)
	at com.zaxxer.hikari.pool.PoolBase.newConnection(PoolBase.java:358)
	at com.zaxxer.hikari.pool.PoolBase.newPoolEntry(PoolBase.java:206)
	at com.zaxxer.hikari.pool.HikariPool.createPoolEntry(HikariPool.java:477)
	at com.zaxxer.hikari.pool.HikariPool.checkFailFast(HikariPool.java:560)
	at com.zaxxer.hikari.pool.HikariPool.<init>(HikariPool.java:115)
	at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:112)
	at org.springframework.jdbc.datasource.DataSourceUtils.fetchConnection(DataSourceUtils.java:159)
	at org.springframework.jdbc.datasource.DataSourceUtils.doGetConnection(DataSourceUtils.java:117)
	at org.springframework.jdbc.datasource.DataSourceUtils.getConnection(DataSourceUtils.java:80)
	at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:376)
	at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:406)
2022-11-15 14:07:33,821 [main] [-] ERROR 🐳 [gvenzl/oracle-xe:18.4.0-slim] - Log output from the failed container:
CONTAINER: starting up...
CONTAINER: first database startup, initializing...
CONTAINER: uncompressing database data files, please wait...
CONTAINER: done uncompressing database data files, duration: 61 seconds.
CONTAINER: starting up Oracle Database...

LSNRCTL for Linux: Version 18.0.0.0.0 - Production on 15-NOV-2022 06:04:35

Copyright (c) 1991, 2018, Oracle.  All rights reserved.

Starting /opt/oracle/product/18c/dbhomeXE/bin/tnslsnr: please wait...

TNSLSNR for Linux: Version 18.0.0.0.0 - Production
System parameter file is /opt/oracle/product/18c/dbhomeXE/network/admin/listener.ora
Log messages written to /opt/oracle/diag/tnslsnr/3e76a299c6e2/listener/alert/log.xml
Listening on: (DESCRIPTION=(ADDRESS=(PROTOCOL=ipc)(KEY=EXTPROC_FOR_XE)))
Listening on: (DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=0.0.0.0)(PORT=1521)))

Connecting to (DESCRIPTION=(ADDRESS=(PROTOCOL=IPC)(KEY=EXTPROC_FOR_XE)))
STATUS of the LISTENER
------------------------
Alias                     LISTENER
Version                   TNSLSNR for Linux: Version 18.0.0.0.0 - Production
Start Date                15-NOV-2022 06:04:42
Uptime                    0 days 0 hr. 0 min. 7 sec
Trace Level               off
Security                  ON: Local OS Authentication
SNMP                      OFF
Default Service           XE
Listener Parameter File   /opt/oracle/product/18c/dbhomeXE/network/admin/listener.ora
Listener Log File         /opt/oracle/diag/tnslsnr/3e76a299c6e2/listener/alert/log.xml
Listening Endpoints Summary...
  (DESCRIPTION=(ADDRESS=(PROTOCOL=ipc)(KEY=EXTPROC_FOR_XE)))
  (DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=0.0.0.0)(PORT=1521)))
The listener supports no services
The command completed successfully

Relevant log output

No response

Additional Information

No response

[eddumelendez]

@yongchuncao can you share more details about how OracleContainer is used? If you can provide a reproducible example, it would be helpful

[yongchuncao]

@yongchuncao can you share more details about how OracleContainer is used? If you can provide a reproducible example, it would be helpful

@eddumelendez Here is my test code:

      HikariDataSource hikariDataSource = new HikariDataSource();
      hikariDataSource.setDriverClassName("org.testcontainers.jdbc.ContainerDatabaseDriver");
      hikariDataSource.setJdbcUrl("jdbc:tc:oracle:18.4.0-slim:///?TC_DAEMON=true");
      hikariDataSource.setUsername("test");
      hikariDataSource.setPassword("test");
      JdbcTemplate jdbcTemplate = new JdbcTemplate(hikariDataSource);
      jdbcTemplate.execute("SQL");

[eddumelendez]

Please provide a github repository or a zip attached where mvn or gradle can be executed to reproduce the issue and containing an expected test.

[yongchuncao]

Please provide a github repository or a zip attached where mvn or gradle can be executed to reproduce the issue and containing an expected test.

test.zip

[eddumelendez]

I had to use the dependency below and change the @Test annotation to JUnit4

<dependency>
  <groupId>com.oracle.database.jdbc</groupId>
  <artifactId>ojdbc6</artifactId>
  <version>11.2.0.4</version>
  <scope>runtime</scope>
</dependency>

but got this error java.sql.SQLSyntaxErrorException: ORA-00903: invalid table name.

@kiview can you run it on windows, please?

[bastoker]

@eddumelendez I've ran the test.zip reproduction example on Windows 10 and the test runs successfully here from IntelliJ if I use the same ojdbc6 dependency as you stated:

<dependency>
  <groupId>com.oracle.database.jdbc</groupId>
  <artifactId>ojdbc6</artifactId>
  <version>11.2.0.4</version>
  <scope>runtime</scope>
</dependency>

I didn't need to change anything to JUnit4 BTW.

I did had to change the table in the SQL DDL to order instead of the reserved name User.

My system:

• Windows 10
• Docker version 4.14.1
• Java 8

[eddumelendez]

Thanks @bastoker ! I'm closing this issue.