Skip to content

MSSQL Server throws Prelogin Warning but then works. #3079

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

Open
marvinosswald opened this issue Aug 6, 2020 · 16 comments
Open

MSSQL Server throws Prelogin Warning but then works. #3079

marvinosswald opened this issue Aug 6, 2020 · 16 comments

Comments

@marvinosswald
Copy link

i get prelogin warning messages after container boot, but it eventually stops and my sql import script runs just fine.
Afterwards the rest of my test runs perfectly, i'd just like to know how i could wait for something or improve this behaviour in anyway.

Aug 06, 2020 9:17:30 AM com.microsoft.sqlserver.jdbc.SQLServerConnection Prelogin
WARNING: ConnectionID:1 ClientConnectionId: e4e44c35-9473-4c70-ab46-24f526599b5c Prelogin error: host localhost port 32787 Unexpected end of prelogin response after 0 bytes read
Aug 06, 2020 9:17:30 AM com.microsoft.sqlserver.jdbc.SQLServerConnection Prelogin
WARNING: ConnectionID:1 ClientConnectionId: 808607de-dc0c-45b4-bbde-c03e310426d8 Prelogin error: host localhost port 32787 Unexpected end of prelogin response after 0 bytes read
Aug 06, 2020 9:17:31 AM com.microsoft.sqlserver.jdbc.SQLServerConnection Prelogin
WARNING: ConnectionID:1 ClientConnectionId: 6b866882-e0c2-4a93-82d7-5261dc061492 Prelogin error: host localhost port 32787 Unexpected end of prelogin response after 0 bytes read
Aug 06, 2020 9:17:31 AM com.microsoft.sqlserver.jdbc.SQLServerConnection Prelogin
WARNING: ConnectionID:1 ClientConnectionId: d85f4d62-45b0-4b40-b601-a24a2bb3f48e Prelogin error: host localhost port 32787 Unexpected end of prelogin response after 0 bytes read
Aug 06, 2020 9:17:32 AM com.microsoft.sqlserver.jdbc.SQLServerConnection Prelogin
WARNING: ConnectionID:1 ClientConnectionId: 01370df2-2393-4888-8e98-6b2cd8a335e0 Prelogin error: host localhost port 32787 Unexpected end of prelogin response after 0 bytes read
Aug 06, 2020 9:17:33 AM com.microsoft.sqlserver.jdbc.SQLServerConnection Prelogin
WARNING: ConnectionID:1 ClientConnectionId: c57ee0b6-b86c-4a77-a82c-d72e82072595 Prelogin error: host localhost port 32787 Unexpected end of prelogin response after 0 bytes read
Aug 06, 2020 9:17:34 AM com.microsoft.sqlserver.jdbc.SQLServerConnection Prelogin
WARNING: ConnectionID:1 ClientConnectionId: 374d4277-fcd2-4684-a080-ba2c20b91ee7 Prelogin error: host localhost port 32787 Unexpected end of prelogin response after 0 bytes read

This is my extended MssqlContainer, i've tried adding a line to wait for a specific log line but it doesn't seem to make any difference.

public class MyMSSQLContainer extends MSSQLServerContainer<MyMSSQLContainer> {
	private static final String IMAGE_VERSION = "mcr.microsoft.com/mssql/server:2017-CU12";
	private static MyMSSQLContainer container;

	private MyMSSQLContainer() {
		super(IMAGE_VERSION);
	}

	public static MyMSSQLContainer getInstance() {
		if (container == null) {
			container = new MyMSSQLContainer().waitingFor(Wait.forLogMessage("*SQL Server is now ready for client connections*", 1));
		}
		return container;
	}

	@Override
	public void start() {
		super.start();
	}

	@Override
	public void stop() {
		//do nothing, JVM handles shut down
	}
}

This is my base test class where i init the container and run the schema and data init script..

public abstract class AbstractApiTest {
	//for ci testing: https://www.testcontainers.org/supported_docker_environment/continuous_integration/bitbucket_pipelines/
	public static MSSQLServerContainer<MyMSSQLContainer> mssqlServerContainer = MyMSSQLContainer.getInstance();

	@Autowired
	MockMvc mockMvc;

	@Autowired
	ObjectMapper objectMapper;

	static {
		mssqlServerContainer.start();
		ScriptUtils.runInitScript(new JdbcDatabaseDelegate(mssqlServerContainer, ""), "setup.sql");
	}

	static class Initializer implements ApplicationContextInitializer<ConfigurableApplicationContext> {

		public void initialize(ConfigurableApplicationContext configurableApplicationContext) {
			TestPropertyValues
				.of(
					"spring.datasource.url=" + mssqlServerContainer.getJdbcUrl(),
					"spring.datasource.username=" + mssqlServerContainer.getUsername(),
					"spring.datasource.password=" + mssqlServerContainer.getPassword()
				)
				.applyTo(configurableApplicationContext.getEnvironment());
		}
	}
}
@stale
Copy link

stale bot commented Nov 7, 2020

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. If you believe this is a mistake, please reply to this comment to keep it open. If there isn't one already, a PR to fix or at least reproduce the problem in a test case will always help us get back on track to tackle this.

@stale stale bot added the stale label Nov 7, 2020
@franklsm1
Copy link

Seeing this same issue as well, when using a r2dbc connection.

@stale stale bot removed the stale label Nov 19, 2020
@AB-xdev
Copy link
Contributor

AB-xdev commented May 6, 2021

@rnorth
Copy link
Member

rnorth commented May 6, 2021

Hmm, I've not had a chance to dig into this, but it sounds like there's a log warning being emitted when Testcontainers is testing the JDBC connection while the container is starting.

Is the problem just log spam, or is there some other problem?

@AB-xdev
Copy link
Contributor

AB-xdev commented May 6, 2021

I think it's just log spam (however I'm not 100% sure) looks like the port is exposed but the SQL Server is not fully setup / starting.
After the container/server says Server is listening on [ ... ] the warning is gone in our tests.

@tsmets
Copy link

tsmets commented May 31, 2021

I have a similar issue here :

@csolem
Copy link

csolem commented Nov 11, 2021

Same here with version 1.16.2. A hacky workaround that avoids the warnings in our case:

new MSSQLServerContainer<>("mcr.microsoft.com/mssql/server:2017-latest")
      .withStartupCheckStrategy(new MinimumDurationRunningStartupCheckStrategy(Duration.ofSeconds(5)));

@namgaxilem
Copy link

Still getting this issue, the insert and select still successful but still get warning and throw SQLException in Spring RestController:

@GetMapping("/v1/user-request/")
public String getUserRequest(@RequestParam Long id) throws SQLException {
    Optional<UserRequest> list = userRequestRepository.findById(id);
    return list.get().getData();
}

@Danielliudov
Copy link

I am experiencing the same issue is there any resolution to it?

@anderso
Copy link

anderso commented Apr 25, 2023

Same here, annoying stderr messages logged while container is starting up. I believe this loop executing the test query is triggering it:

protected void waitUntilContainerStarted() {
logger()
.info(
"Waiting for database connection to become available at {} using query '{}'",
getJdbcUrl(),
getTestQueryString()
);
// Repeatedly try and open a connection to the DB and execute a test query
long start = System.currentTimeMillis();
Exception lastConnectionException = null;
while (System.currentTimeMillis() < start + (1000 * startupTimeoutSeconds)) {
if (!isRunning()) {
Thread.sleep(100L);
} else {
try (Connection connection = createConnection(""); Statement statement = connection.createStatement()) {
boolean testQuerySucceeded = statement.execute(this.getTestQueryString());
if (testQuerySucceeded) {
return;
}
} catch (NoDriverFoundException e) {
// we explicitly want this exception to fail fast without retries
throw e;
} catch (Exception e) {
lastConnectionException = e;
// ignore so that we can try again
logger().debug("Failure when trying test query", e);
Thread.sleep(100L);
}
}
}
throw new IllegalStateException(
String.format(
"Container is started, but cannot be accessed by (JDBC URL: %s), please check container logs",
this.getJdbcUrl()
),
lastConnectionException
);
}

@zahidzia
Copy link

zahidzia commented Aug 3, 2023

Any updates on how to fix this annoying log spam?

@anderso
Copy link

anderso commented Aug 29, 2023

The mssql jdbc driver is logging with java util logging to the logger named com.microsoft.sqlserver.jdbc.Connection

https://github.com/microsoft/mssql-jdbc/blob/0f3e0a10f2f85b5b357811907fdb487d63e49830/src/main/java/com/microsoft/sqlserver/jdbc/SQLServerConnection.java#L1213-L1214

So the easiest way to disable it would be disable the warning level of this logger, how to do it depends on your logging setup.

Another alternative would be to override waitUntilContainerStarted, the question is what to replace it with, is there an alternative way to check if mssql has started? This code is common for all jdbc containers so I'm guessing only the mssql driver logs this as warning or this would have been fixed by now.

Another alternative is to wait for a while so that when this method is called the database should already be up, as suggested above.

@email2muthu4
Copy link

I am also facing similar issue . Anyone find the solution ?

Jul 28, 2024 1:45:20 PM com.microsoft.sqlserver.jdbc.SQLServerConnection prelogin
WARNING: ConnectionID:1 ClientConnectionId: f4682bb4-bbca-4b39-8bc9-0a031923f52a Prelogin error: host localhost port 61904 Unexpected end of prelogin response after 0 bytes read

@aistisdev
Copy link

aistisdev commented Oct 10, 2024

Same issue, but it does not start ever

EDIT: in case someone else also cannot start, I have found a working combination for java 21. Still have the logged errors, but now at least it connects after a few attempts:

                <dependency>
			<groupId>org.testcontainers</groupId>
			<artifactId>mssqlserver</artifactId>
			<version>1.20.2</version>
			<scope>test</scope>
		</dependency>

		<dependency>
			<groupId>com.microsoft.sqlserver</groupId>
			<artifactId>mssql-jdbc</artifactId>
			<version>12.6.3.jre11</version>
		</dependency>
    @Rule
    public static MSSQLServerContainer mssqlserver = new MSSQLServerContainer<>("mcr.microsoft.com/mssql/server:2022-CU15-GDR1-ubuntu-22.04").acceptLicense()
            .waitingFor(Wait.forListeningPort());

    @BeforeAll
    static void init(){
        mssqlserver.start();
        ....
    }

@rieckpil
Copy link

rieckpil commented Jan 9, 2025

As mentioned above, the MS SQL JDBC driver uses the java.util.Logging which, by default, logs to stderr.

To get rid of the noise, you can override the log level:

val logger = Logger.getLogger("com.microsoft.sqlserver.jdbc.internals.SQLServerConnection")
logger.level = Level.SEVERE

Java:

Logger logger = Logger.getLogger("com.microsoft.sqlserver.jdbc.internals.SQLServerConnection");
logger.setLevel(Level.SEVERE);

@ventod
Copy link

ventod commented May 16, 2025

As mentioned above, the MS SQL JDBC driver uses the java.util.Logging which, by default, logs to stderr.

To get rid of the noise, you can override the log level:

val logger = Logger.getLogger("com.microsoft.sqlserver.jdbc.internals.SQLServerConnection")
logger.level = Level.SEVERE

Java:

Logger logger = Logger.getLogger("com.microsoft.sqlserver.jdbc.internals.SQLServerConnection");
logger.setLevel(Level.SEVERE);

for me this is not working. I'm still getting tons of

"""
May 16, 2025 4:31:18 PM com.microsoft.sqlserver.jdbc.SQLServerConnection prelogin
WARNING: ConnectionID:2 ClientConnectionId: 680984d2-d2fb-4866-b68b-af61353fbe31 Prelogin error: host localhost port 32824 Unexpected end of prelogin response after 0 bytes read
May 16, 2025 4:31:18 PM com.microsoft.sqlserver.jdbc.SQLServerConnection prelogin
WARNING: ConnectionID:3 ClientConnectionId: 79e5ba0e-6bb2-4fce-9727-d36148eb8ec6 Prelogin error: host localhost port 32824 Error reading prelogin response: Connection reset ClientConnectionId:79e5ba0e-6bb2-4fce-9727-d36148eb8ec6
"""
Which imo should be expected because those logs are coming from inside the container itself

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests