diff --git a/src/main/java/com/microsoft/sqlserver/jdbc/PerformanceActivity.java b/src/main/java/com/microsoft/sqlserver/jdbc/PerformanceActivity.java new file mode 100644 index 000000000..32a89299e --- /dev/null +++ b/src/main/java/com/microsoft/sqlserver/jdbc/PerformanceActivity.java @@ -0,0 +1,31 @@ +/* + * Microsoft JDBC Driver for SQL Server Copyright(c) Microsoft Corporation All rights reserved. This program is made + * available under the terms of the MIT License. See the LICENSE file in the project root for more information. + */ + +package com.microsoft.sqlserver.jdbc; + +/** + * Enum representing different performance activities. + */ +public enum PerformanceActivity { + CONNECTION("Connection"), + TOKEN_ACQUISITION("Token acquisition"), + LOGIN("Login"), + PRELOGIN("Prelogin"); + + private final String activity; + + PerformanceActivity(String activity) { + this.activity = activity; + } + + public String activity() { + return activity; + } + + @Override + public String toString() { + return activity; + } +} diff --git a/src/main/java/com/microsoft/sqlserver/jdbc/PerformanceLog.java b/src/main/java/com/microsoft/sqlserver/jdbc/PerformanceLog.java new file mode 100644 index 000000000..df8adc85a --- /dev/null +++ b/src/main/java/com/microsoft/sqlserver/jdbc/PerformanceLog.java @@ -0,0 +1,101 @@ +/* + * Microsoft JDBC Driver for SQL Server Copyright(c) Microsoft Corporation All rights reserved. This program is made + * available under the terms of the MIT License. See the LICENSE file in the project root for more information. + */ + +package com.microsoft.sqlserver.jdbc; + +import java.util.logging.Level; +import java.util.logging.Logger; + +class PerformanceLog { + + static final java.util.logging.Logger perfLoggerConnection = java.util.logging.Logger + .getLogger("com.microsoft.sqlserver.jdbc.PerformanceMetrics.Connection"); + + private static PerformanceLogCallback callback; + private static boolean callbackInitialized = false; + + /** + * Register a callback for performance log events. + * + * @param cb The callback to register. + */ + public static synchronized void registerCallback(PerformanceLogCallback cb) { + if (callbackInitialized) { + throw new IllegalStateException("Callback has already been set"); + } + callback = cb; + callbackInitialized = true; + } + + /** + * Unregister the callback for performance log events. + */ + public static synchronized void unregisterCallback() { + callback = null; + callbackInitialized = false; + } + + //TODO + //More loggers to be added here e.g. com.microsoft.sqlserver.jdbc.PerformanceMetrics.Statement + + public static class Scope implements AutoCloseable { + private Logger logger; + private String logPrefix; + private PerformanceActivity activity; + private long startTime; + private final boolean enabled; + + private Exception exception; + + public Scope(Logger logger, String logPrefix, PerformanceActivity activity) { + + // Check if logging is enabled + this.enabled = logger.isLoggable(Level.INFO) || (callback != null); + + if (enabled) { + this.logger = logger; + this.logPrefix = logPrefix; + this.activity = activity; + this.startTime = System.currentTimeMillis(); + } + } + + public void setException(Exception e) { + this.exception = e; + } + + @Override + public void close() { + + if (!enabled) { + return; + } + + long endTime = System.currentTimeMillis(); + long duration = endTime - startTime; + + if (callback != null) { + try { + callback.publish(duration, activity, exception); + } catch (Exception e) { + logger.info(String.format("Failed to publish performance log: %s", e.getMessage())); + } + } + + if (logger != null && logger.isLoggable(Level.INFO)) { + if (exception != null) { + logger.info(String.format("%s %s, duration: %dms, exception: %s", logPrefix, activity, duration, exception.getMessage())); + } else { + logger.info(String.format("%s %s, duration: %dms", logPrefix, activity, duration)); + } + } + + } + } + + public static Scope createScope(Logger logger, String logPrefix, PerformanceActivity activity) { + return new Scope(logger, logPrefix, activity); + } +} diff --git a/src/main/java/com/microsoft/sqlserver/jdbc/PerformanceLogCallback.java b/src/main/java/com/microsoft/sqlserver/jdbc/PerformanceLogCallback.java new file mode 100644 index 000000000..b433c34b7 --- /dev/null +++ b/src/main/java/com/microsoft/sqlserver/jdbc/PerformanceLogCallback.java @@ -0,0 +1,22 @@ +/* + * Microsoft JDBC Driver for SQL Server Copyright(c) Microsoft Corporation All rights reserved. This program is made + * available under the terms of the MIT License. See the LICENSE file in the project root for more information. + */ + +package com.microsoft.sqlserver.jdbc; + +/** + * Callback interface for publishing performance logs. + */ +public interface PerformanceLogCallback { + + /** + * Publish a performance log entry. + * + * @param durationMs The duration of the operation in milliseconds. + * @param activity The type of activity being logged. + * @param exception An exception, if an error occurred. + */ + void publish(long durationMs, PerformanceActivity activity, Exception exception) throws Exception; + +} \ No newline at end of file diff --git a/src/main/java/com/microsoft/sqlserver/jdbc/SQLServerConnection.java b/src/main/java/com/microsoft/sqlserver/jdbc/SQLServerConnection.java index 836e3481f..098392b13 100644 --- a/src/main/java/com/microsoft/sqlserver/jdbc/SQLServerConnection.java +++ b/src/main/java/com/microsoft/sqlserver/jdbc/SQLServerConnection.java @@ -2229,128 +2229,142 @@ private void sleepForInterval(long interval) { } Connection connect(Properties propsIn, SQLServerPooledConnection pooledConnection) throws SQLServerException { - int loginTimeoutSeconds = SQLServerDriverIntProperty.LOGIN_TIMEOUT.getDefaultValue(); - if (propsIn != null) { - String sPropValue = propsIn.getProperty(SQLServerDriverIntProperty.LOGIN_TIMEOUT.toString()); + try (PerformanceLog.Scope connectScope = PerformanceLog.createScope(PerformanceLog.perfLoggerConnection, + traceID, PerformanceActivity.CONNECTION)) { try { - if (null != sPropValue && sPropValue.length() > 0) { - int sPropValueInt = Integer.parseInt(sPropValue); - if (0 != sPropValueInt) { // Use the default timeout in case of a zero value - loginTimeoutSeconds = sPropValueInt; - } - } - } catch (NumberFormatException e) { - MessageFormat form = new MessageFormat(SQLServerException.getErrString("R_invalidTimeOut")); - Object[] msgArgs = {sPropValue}; - SQLServerException.makeFromDriverError(this, this, form.format(msgArgs), null, false); - } - } - - // Interactive auth may involve MFA which require longer timeout - if (SqlAuthentication.ACTIVE_DIRECTORY_INTERACTIVE.toString().equalsIgnoreCase(authenticationString)) { - loginTimeoutSeconds *= 10; - } - - long elapsedSeconds = 0; - long start = System.currentTimeMillis(); - - // Any existing enclave session would be invalid, make sure it is invalidated. - // For example, if this is a session recovery reconnect. - // - invalidateEnclaveSessionCache(); - for (int connectRetryAttempt = 0, tlsRetryAttempt = 0;;) { - try { - if (0 == elapsedSeconds || elapsedSeconds < loginTimeoutSeconds) { - if (0 < tlsRetryAttempt && INTERMITTENT_TLS_MAX_RETRY > tlsRetryAttempt) { - if (connectionlogger.isLoggable(Level.FINE)) { - connectionlogger.fine("TLS retry " + tlsRetryAttempt + " of " + INTERMITTENT_TLS_MAX_RETRY - + " elapsed time " + elapsedSeconds + " secs"); - } - } else if (0 < connectRetryAttempt) { - if (connectionlogger.isLoggable(Level.FINE)) { - connectionlogger.fine("Retrying connection " + connectRetryAttempt + " of " - + connectRetryCount + " elapsed time " + elapsedSeconds + " secs"); + int loginTimeoutSeconds = SQLServerDriverIntProperty.LOGIN_TIMEOUT.getDefaultValue(); + if (propsIn != null) { + String sPropValue = propsIn.getProperty(SQLServerDriverIntProperty.LOGIN_TIMEOUT.toString()); + try { + if (null != sPropValue && sPropValue.length() > 0) { + int sPropValueInt = Integer.parseInt(sPropValue); + if (0 != sPropValueInt) { // Use the default timeout in case of a zero value + loginTimeoutSeconds = sPropValueInt; + } } + } catch (NumberFormatException e) { + MessageFormat form = new MessageFormat(SQLServerException.getErrString("R_invalidTimeOut")); + Object[] msgArgs = { sPropValue }; + SQLServerException.makeFromDriverError(this, this, form.format(msgArgs), null, false); } + } - return connectInternal(propsIn, pooledConnection); + // Interactive auth may involve MFA which require longer timeout + if (SqlAuthentication.ACTIVE_DIRECTORY_INTERACTIVE.toString().equalsIgnoreCase(authenticationString)) { + loginTimeoutSeconds *= 10; } - } catch (SQLServerException e) { - elapsedSeconds = ((System.currentTimeMillis() - start) / 1000L); - // special case for TLS intermittent failures: no wait retries - if (SQLServerException.DRIVER_ERROR_INTERMITTENT_TLS_FAILED == e.getDriverErrorCode() - && tlsRetryAttempt < INTERMITTENT_TLS_MAX_RETRY && elapsedSeconds < loginTimeoutSeconds) { - if (connectionlogger.isLoggable(Level.FINE)) { - connectionlogger.fine( - "Connection failed during SSL handshake. Retrying due to an intermittent TLS 1.2 failure issue. Retry attempt = " - + tlsRetryAttempt + "."); - } - tlsRetryAttempt++; - } else { - // TLS max retry exceeded - if (tlsRetryAttempt > INTERMITTENT_TLS_MAX_RETRY) { - if (connectionlogger.isLoggable(Level.FINE)) { - connectionlogger.fine("Connection failed during SSL handshake. Maximum retry attempt (" - + INTERMITTENT_TLS_MAX_RETRY + ") reached. "); - } - } + long elapsedSeconds = 0; + long start = System.currentTimeMillis(); - if (0 == connectRetryCount) { - // connection retry disabled - throw e; - } else if (connectRetryAttempt++ >= connectRetryCount) { - // maximum connection retry count reached - if (connectionlogger.isLoggable(Level.FINE)) { - connectionlogger.fine("Connection failed. Maximum connection retry count " - + connectRetryCount + " reached."); + // Any existing enclave session would be invalid, make sure it is invalidated. + // For example, if this is a session recovery reconnect. + // + invalidateEnclaveSessionCache(); + for (int connectRetryAttempt = 0, tlsRetryAttempt = 0;;) { + try { + if (0 == elapsedSeconds || elapsedSeconds < loginTimeoutSeconds) { + if (0 < tlsRetryAttempt && INTERMITTENT_TLS_MAX_RETRY > tlsRetryAttempt) { + if (connectionlogger.isLoggable(Level.FINE)) { + connectionlogger + .fine("TLS retry " + tlsRetryAttempt + " of " + INTERMITTENT_TLS_MAX_RETRY + + " elapsed time " + elapsedSeconds + " secs"); + } + } else if (0 < connectRetryAttempt) { + if (connectionlogger.isLoggable(Level.FINE)) { + connectionlogger.fine("Retrying connection " + connectRetryAttempt + " of " + + connectRetryCount + " elapsed time " + elapsedSeconds + " secs"); + } + } + + return connectInternal(propsIn, pooledConnection); } - throw e; - } else { - // Only retry if matches configured CRL rules, or transient error (if CRL is not in use) - SQLServerError sqlServerError = e.getSQLServerError(); - if (null == sqlServerError) { - throw e; + } catch (SQLServerException e) { + elapsedSeconds = ((System.currentTimeMillis() - start) / 1000L); + + // special case for TLS intermittent failures: no wait retries + if (SQLServerException.DRIVER_ERROR_INTERMITTENT_TLS_FAILED == e.getDriverErrorCode() + && tlsRetryAttempt < INTERMITTENT_TLS_MAX_RETRY + && elapsedSeconds < loginTimeoutSeconds) { + if (connectionlogger.isLoggable(Level.FINE)) { + connectionlogger.fine( + "Connection failed during SSL handshake. Retrying due to an intermittent TLS 1.2 failure issue. Retry attempt = " + + tlsRetryAttempt + "."); + } + tlsRetryAttempt++; } else { - ConfigurableRetryRule rule = ConfigurableRetryLogic.getInstance() - .searchRuleSet(sqlServerError.getErrorNumber(), "connection"); + // TLS max retry exceeded + if (tlsRetryAttempt > INTERMITTENT_TLS_MAX_RETRY) { + if (connectionlogger.isLoggable(Level.FINE)) { + connectionlogger + .fine("Connection failed during SSL handshake. Maximum retry attempt (" + + INTERMITTENT_TLS_MAX_RETRY + ") reached. "); + } + } - if (null == rule) { - if (ConfigurableRetryLogic.getInstance().getReplaceFlag()) { + if (0 == connectRetryCount) { + // connection retry disabled + throw e; + } else if (connectRetryAttempt++ >= connectRetryCount) { + // maximum connection retry count reached + if (connectionlogger.isLoggable(Level.FINE)) { + connectionlogger.fine("Connection failed. Maximum connection retry count " + + connectRetryCount + " reached."); + } + throw e; + } else { + // Only retry if matches configured CRL rules, or transient error (if CRL is not + // in use) + SQLServerError sqlServerError = e.getSQLServerError(); + if (null == sqlServerError) { throw e; } else { - if (!TransientError.isTransientError(sqlServerError)) { - throw e; + ConfigurableRetryRule rule = ConfigurableRetryLogic.getInstance() + .searchRuleSet(sqlServerError.getErrorNumber(), "connection"); + + if (null == rule) { + if (ConfigurableRetryLogic.getInstance().getReplaceFlag()) { + throw e; + } else { + if (!TransientError.isTransientError(sqlServerError)) { + throw e; + } + } } } - } - } - // check if there's time to retry, no point to wait if no time left - if ((elapsedSeconds + connectRetryInterval) >= loginTimeoutSeconds) { - if (connectionlogger.isLoggable(Level.FINEST)) { - connectionlogger - .finest("Connection failed. No time left to retry timeout will be exceeded:" - + " elapsed time(" + elapsedSeconds + ")s + connectRetryInterval(" - + connectRetryInterval + ")s >= loginTimeout(" + loginTimeoutSeconds - + ")s"); - } - throw e; - } + // check if there's time to retry, no point to wait if no time left + if ((elapsedSeconds + connectRetryInterval) >= loginTimeoutSeconds) { + if (connectionlogger.isLoggable(Level.FINEST)) { + connectionlogger + .finest("Connection failed. No time left to retry timeout will be exceeded:" + + " elapsed time(" + elapsedSeconds + + ")s + connectRetryInterval(" + + connectRetryInterval + ")s >= loginTimeout(" + + loginTimeoutSeconds + + ")s"); + } + throw e; + } - // wait for connectRetryInterval before retry - if (connectionlogger.isLoggable(Level.FINEST)) { - connectionlogger.finest(toString() + "Connection failed on transient error " - + sqlServerError.getErrorNumber() + ". Wait for connectRetryInterval(" - + connectRetryInterval + ")s before retry."); - } + // wait for connectRetryInterval before retry + if (connectionlogger.isLoggable(Level.FINEST)) { + connectionlogger.finest(toString() + "Connection failed on transient error " + + sqlServerError.getErrorNumber() + ". Wait for connectRetryInterval(" + + connectRetryInterval + ")s before retry."); + } - if (connectRetryAttempt > 1) { - // We do not sleep for first retry; first retry is immediate - sleepForInterval(TimeUnit.SECONDS.toMillis(connectRetryInterval)); + if (connectRetryAttempt > 1) { + // We do not sleep for first retry; first retry is immediate + sleepForInterval(TimeUnit.SECONDS.toMillis(connectRetryInterval)); + } + } } } } + } catch (Exception e) { + connectScope.setException(e); + throw e; } } } @@ -3687,374 +3701,416 @@ private void logConnectFailure(int attemptNumber, SQLServerException e, SQLServe */ private void login(String primary, String primaryInstanceName, int primaryPortNumber, String mirror, FailoverInfo foActual, int timeout, long timerStart) throws SQLServerException { - // standardLogin would be false only for db mirroring scenarios. It would be true - // for all other cases, including multiSubnetFailover - - final boolean isDBMirroring = null != mirror || null != foActual; - - int fedauthRetryInterval = BACKOFF_INTERVAL; // milliseconds to sleep (back off) between attempts. - - long timeoutUnitInterval; - long timeForFirstTry = 0; // time it took to do 1st try in ms - - boolean useFailoverHost = false; - FailoverInfo tempFailover = null; - // This is the failover server info place holder - ServerPortPlaceHolder currentFOPlaceHolder = null; - // This is the primary server placeHolder - ServerPortPlaceHolder currentPrimaryPlaceHolder = null; - - if (null != foActual) { - tempFailover = foActual; - useFailoverHost = foActual.getUseFailoverPartner(); - } else { - if (isDBMirroring) { - // Create a temporary class with the mirror info from the user - tempFailover = new FailoverInfo(mirror, false); - } - } + try (PerformanceLog.Scope loginScope = PerformanceLog.createScope(PerformanceLog.perfLoggerConnection, traceID, + PerformanceActivity.LOGIN)) { + try { + // standardLogin would be false only for db mirroring scenarios. It would be + // true + // for all other cases, including multiSubnetFailover - // useParallel is set to true only for the first connection - // when multiSubnetFailover is set to true. In all other cases, it is set - // to false. - boolean useParallel = getMultiSubnetFailover(); - boolean useTnir = getTransparentNetworkIPResolution(); + final boolean isDBMirroring = null != mirror || null != foActual; - long intervalExpire; + int fedauthRetryInterval = BACKOFF_INTERVAL; // milliseconds to sleep (back off) between attempts. - if (0 == timeout) { - timeout = SQLServerDriverIntProperty.LOGIN_TIMEOUT.getDefaultValue(); - } - long timerTimeout = timeout * 1000L; // ConnectTimeout is in seconds, we need timer millis - timerExpire = timerStart + timerTimeout; + long timeoutUnitInterval; + long timeForFirstTry = 0; // time it took to do 1st try in ms - // For non-dbmirroring, non-tnir and non-multisubnetfailover scenarios, full time out would be used as time - // slice. - if (isDBMirroring || useParallel) { - timeoutUnitInterval = (long) (TIMEOUTSTEP * timerTimeout); - } else if (useTnir) { - timeoutUnitInterval = (long) (TIMEOUTSTEP_TNIR * timerTimeout); - } else { - timeoutUnitInterval = timerTimeout; - } - intervalExpire = timerStart + timeoutUnitInterval; + boolean useFailoverHost = false; + FailoverInfo tempFailover = null; + // This is the failover server info place holder + ServerPortPlaceHolder currentFOPlaceHolder = null; + // This is the primary server placeHolder + ServerPortPlaceHolder currentPrimaryPlaceHolder = null; - // This is needed when the host resolves to more than 64 IP addresses. In that case, TNIR is ignored - // and the original timeout is used instead of the timeout slice. - long intervalExpireFullTimeout = timerStart + timerTimeout; + if (null != foActual) { + tempFailover = foActual; + useFailoverHost = foActual.getUseFailoverPartner(); + } else { + if (isDBMirroring) { + // Create a temporary class with the mirror info from the user + tempFailover = new FailoverInfo(mirror, false); + } + } - if (loggerResiliency.isLoggable(Level.FINER)) { - loggerResiliency.finer(toString() + " Connection open - start time: " + timeout + " time out time: " - + timerExpire + " timeout unit interval: " + timeoutUnitInterval); - } + // useParallel is set to true only for the first connection + // when multiSubnetFailover is set to true. In all other cases, it is set + // to false. + boolean useParallel = getMultiSubnetFailover(); + boolean useTnir = getTransparentNetworkIPResolution(); - // Initialize loop variables - int attemptNumber = 0; - SQLServerError sqlServerError = null; + long intervalExpire; - // indicates the no of times the connection was routed to a different server - int noOfRedirections = 0; - int maxNoOfRedirections = 10; - // Only three ways out of this loop: - // 1) Successfully connected - // 2) Parser threw exception while main timer was expired - // 3) Parser threw logon failure-related exception (LOGON_FAILED, PASSWORD_EXPIRED, etc) - // - // Of these methods, only #1 exits normally. This preserves the call stack on the exception - // back into the parser for the error cases. - while (true) { - clientConnectionId = null; - state = State.INITIALIZED; + if (0 == timeout) { + timeout = SQLServerDriverIntProperty.LOGIN_TIMEOUT.getDefaultValue(); + } + long timerTimeout = timeout * 1000L; // ConnectTimeout is in seconds, we need timer millis + timerExpire = timerStart + timerTimeout; - try { - if (isDBMirroring && useFailoverHost) { - if (null == currentFOPlaceHolder) { - // integrated security flag passed here to verify that the linked dll can be loaded - currentFOPlaceHolder = tempFailover.failoverPermissionCheck(this, integratedSecurity); - } - currentConnectPlaceHolder = currentFOPlaceHolder; + // For non-dbmirroring, non-tnir and non-multisubnetfailover scenarios, full + // time out would be used as time + // slice. + if (isDBMirroring || useParallel) { + timeoutUnitInterval = (long) (TIMEOUTSTEP * timerTimeout); + } else if (useTnir) { + timeoutUnitInterval = (long) (TIMEOUTSTEP_TNIR * timerTimeout); } else { - if (routingInfo != null) { - if (loggerRedirection.isLoggable(Level.FINE)) { - loggerRedirection - .fine(toString() + " Connection open - redirecting to server and instance: " - + routingInfo.getFullServerName()); - } - currentPrimaryPlaceHolder = routingInfo; - routingInfo = null; - } else if (null == currentPrimaryPlaceHolder) { - currentPrimaryPlaceHolder = primaryPermissionCheck(primary, primaryInstanceName, - primaryPortNumber); - } - currentConnectPlaceHolder = currentPrimaryPlaceHolder; + timeoutUnitInterval = timerTimeout; } + intervalExpire = timerStart + timeoutUnitInterval; - if (loggerResiliency.isLoggable(Level.FINE) && attemptNumber > 0) { - loggerResiliency.fine(toString() + " Connection open - starting connection retry attempt number: " - + attemptNumber); - } + // This is needed when the host resolves to more than 64 IP addresses. In that + // case, TNIR is ignored + // and the original timeout is used instead of the timeout slice. + long intervalExpireFullTimeout = timerStart + timerTimeout; if (loggerResiliency.isLoggable(Level.FINER)) { - loggerResiliency.finer(toString() + " Connection open - attempt server name: " - + currentConnectPlaceHolder.getServerName() + " port: " - + currentConnectPlaceHolder.getPortNumber() + " InstanceName: " - + currentConnectPlaceHolder.getInstanceName() + " useParallel: " + useParallel); - loggerResiliency.finer(toString() + " Connection open - attempt end time: " + intervalExpire); - loggerResiliency.finer(toString() + " Connection open - attempt number: " + attemptNumber); - } - - // Attempt login. Use Place holder to make sure that the failoverdemand is done. - InetSocketAddress inetSocketAddress = connectHelper(currentConnectPlaceHolder, - timerRemaining(intervalExpire), timeout, useParallel, useTnir, (0 == attemptNumber), // TNIR - // first - // attempt - timerRemaining(intervalExpireFullTimeout)); // Only used when host resolves to >64 IPs - // Successful connection, cache the IP address and port if server supports DNS Cache. - if (serverSupportsDNSCaching) { - dnsCache.put(currentConnectPlaceHolder.getServerName(), inetSocketAddress); - } - - if (isRoutedInCurrentAttempt) { - // we ignore the failoverpartner ENVCHANGE if we got routed so no error needs to be thrown - if (isDBMirroring) { - String msg = SQLServerException.getErrString("R_invalidRoutingInfo"); - terminate(SQLServerException.DRIVER_ERROR_UNSUPPORTED_CONFIG, msg); - } + loggerResiliency.finer(toString() + " Connection open - start time: " + timeout + " time out time: " + + timerExpire + " timeout unit interval: " + timeoutUnitInterval); + } + + // Initialize loop variables + int attemptNumber = 0; + SQLServerError sqlServerError = null; + + // indicates the no of times the connection was routed to a different server + int noOfRedirections = 0; + int maxNoOfRedirections = 10; + // Only three ways out of this loop: + // 1) Successfully connected + // 2) Parser threw exception while main timer was expired + // 3) Parser threw logon failure-related exception (LOGON_FAILED, + // PASSWORD_EXPIRED, etc) + // + // Of these methods, only #1 exits normally. This preserves the call stack on + // the exception + // back into the parser for the error cases. + while (true) { + clientConnectionId = null; + state = State.INITIALIZED; - noOfRedirections++; + try { + if (isDBMirroring && useFailoverHost) { + if (null == currentFOPlaceHolder) { + // integrated security flag passed here to verify that the linked dll can be + // loaded + currentFOPlaceHolder = tempFailover.failoverPermissionCheck(this, integratedSecurity); + } + currentConnectPlaceHolder = currentFOPlaceHolder; + } else { + if (routingInfo != null) { + if (loggerRedirection.isLoggable(Level.FINE)) { + loggerRedirection + .fine(toString() + " Connection open - redirecting to server and instance: " + + routingInfo.getFullServerName()); + } + currentPrimaryPlaceHolder = routingInfo; + routingInfo = null; + } else if (null == currentPrimaryPlaceHolder) { + currentPrimaryPlaceHolder = primaryPermissionCheck(primary, primaryInstanceName, + primaryPortNumber); + } + currentConnectPlaceHolder = currentPrimaryPlaceHolder; + } - if (loggerRedirection.isLoggable(Level.FINE)) { - loggerRedirection - .fine(toString() + " Connection open - redirection count: " + noOfRedirections); - } + if (loggerResiliency.isLoggable(Level.FINE) && attemptNumber > 0) { + loggerResiliency + .fine(toString() + " Connection open - starting connection retry attempt number: " + + attemptNumber); + } - if (noOfRedirections > maxNoOfRedirections) { - MessageFormat form = new MessageFormat(SQLServerException.getErrString("R_multipleRedirections")); - Object[] msgArgs = {maxNoOfRedirections}; - terminate(SQLServerException.DRIVER_ERROR_UNSUPPORTED_CONFIG, form.format(msgArgs)); - } + if (loggerResiliency.isLoggable(Level.FINER)) { + loggerResiliency.finer(toString() + " Connection open - attempt server name: " + + currentConnectPlaceHolder.getServerName() + " port: " + + currentConnectPlaceHolder.getPortNumber() + " InstanceName: " + + currentConnectPlaceHolder.getInstanceName() + " useParallel: " + useParallel); + loggerResiliency + .finer(toString() + " Connection open - attempt end time: " + intervalExpire); + loggerResiliency.finer(toString() + " Connection open - attempt number: " + attemptNumber); + } - // close tds channel - if (tdsChannel != null) - tdsChannel.close(); + // Attempt login. Use Place holder to make sure that the failoverdemand is done. + InetSocketAddress inetSocketAddress = connectHelper(currentConnectPlaceHolder, + timerRemaining(intervalExpire), timeout, useParallel, useTnir, (0 == attemptNumber), // TNIR + // first + // attempt + timerRemaining(intervalExpireFullTimeout)); // Only used when host resolves to >64 IPs + // Successful connection, cache the IP address and port if server supports DNS + // Cache. + if (serverSupportsDNSCaching) { + dnsCache.put(currentConnectPlaceHolder.getServerName(), inetSocketAddress); + } - initResettableValues(); + if (isRoutedInCurrentAttempt) { + // we ignore the failoverpartner ENVCHANGE if we got routed so no error needs to + // be thrown + if (isDBMirroring) { + String msg = SQLServerException.getErrString("R_invalidRoutingInfo"); + terminate(SQLServerException.DRIVER_ERROR_UNSUPPORTED_CONFIG, msg); + } - // reset all params that could have been changed due to ENVCHANGE tokens - // to defaults, excluding those changed due to routing ENVCHANGE token - resetNonRoutingEnvchangeValues(); + noOfRedirections++; - // increase the attempt number. This is not really necessary - // (in fact it does not matter whether we increase it or not) as - // we do not use any timeslicing for multisubnetfailover. However, this - // is done just to be consistent with the rest of the logic. - attemptNumber++; + if (loggerRedirection.isLoggable(Level.FINE)) { + loggerRedirection + .fine(toString() + " Connection open - redirection count: " + noOfRedirections); + } - // useParallel and useTnir should be set to false once we get routed - useParallel = false; - useTnir = false; + if (noOfRedirections > maxNoOfRedirections) { + MessageFormat form = new MessageFormat( + SQLServerException.getErrString("R_multipleRedirections")); + Object[] msgArgs = { maxNoOfRedirections }; + terminate(SQLServerException.DRIVER_ERROR_UNSUPPORTED_CONFIG, form.format(msgArgs)); + } - // When connection is routed for read only application, remaining timer duration is used as a one - // full interval - intervalExpire = timerExpire; + // close tds channel + if (tdsChannel != null) + tdsChannel.close(); + + initResettableValues(); + + // reset all params that could have been changed due to ENVCHANGE tokens + // to defaults, excluding those changed due to routing ENVCHANGE token + resetNonRoutingEnvchangeValues(); + + // increase the attempt number. This is not really necessary + // (in fact it does not matter whether we increase it or not) as + // we do not use any timeslicing for multisubnetfailover. However, this + // is done just to be consistent with the rest of the logic. + attemptNumber++; + + // useParallel and useTnir should be set to false once we get routed + useParallel = false; + useTnir = false; + + // When connection is routed for read only application, remaining timer duration + // is used as a one + // full interval + intervalExpire = timerExpire; + + // if timeout expired, throw. + if (timerHasExpired(timerExpire)) { + MessageFormat form = new MessageFormat( + SQLServerException.getErrString("R_tcpipConnectionFailed")); + Object[] msgArgs = { getServerNameString(currentConnectPlaceHolder.getServerName()), + Integer.toString(currentConnectPlaceHolder.getPortNumber()), + SQLServerException.getErrString("R_timedOutBeforeRouting") }; + String msg = form.format(msgArgs); + terminate(SQLServerException.DRIVER_ERROR_UNSUPPORTED_CONFIG, msg); + } else { + // set isRoutedInCurrentAttempt to false for the next attempt + isRoutedInCurrentAttempt = false; + + continue; + } + } else { + if (loggerResiliency.isLoggable(Level.FINE) && attemptNumber > 0) { + loggerResiliency.fine(toString() + + " Connection open - connection retry succeeded on attempt number: " + + attemptNumber); + } - // if timeout expired, throw. - if (timerHasExpired(timerExpire)) { - MessageFormat form = new MessageFormat( - SQLServerException.getErrString("R_tcpipConnectionFailed")); - Object[] msgArgs = {getServerNameString(currentConnectPlaceHolder.getServerName()), - Integer.toString(currentConnectPlaceHolder.getPortNumber()), - SQLServerException.getErrString("R_timedOutBeforeRouting")}; - String msg = form.format(msgArgs); - terminate(SQLServerException.DRIVER_ERROR_UNSUPPORTED_CONFIG, msg); - } else { - // set isRoutedInCurrentAttempt to false for the next attempt - isRoutedInCurrentAttempt = false; + break; // leave the while loop -- we've successfully connected + } + } catch (SQLServerException e) { - continue; - } - } else { - if (loggerResiliency.isLoggable(Level.FINE) && attemptNumber > 0) { - loggerResiliency.fine(toString() - + " Connection open - connection retry succeeded on attempt number: " + attemptNumber); - } + if (loggerResiliency.isLoggable(Level.FINE) && attemptNumber > 0) { + loggerResiliency + .fine(toString() + " Connection open - connection retry failed on attempt number: " + + attemptNumber); + } - break; // leave the while loop -- we've successfully connected - } - } catch (SQLServerException e) { + if (loggerResiliency.isLoggable(Level.FINER) && (attemptNumber >= connectRetryCount)) { + loggerResiliency + .finer(toString() + + " Connection open - connection failed. Maximum connection retry count " + + connectRetryCount + " reached."); + } - if (loggerResiliency.isLoggable(Level.FINE) && attemptNumber > 0) { - loggerResiliency.fine(toString() + " Connection open - connection retry failed on attempt number: " - + attemptNumber); - } + // estimate time it took to do 1 try + if (attemptNumber == 0) { + timeForFirstTry = (System.currentTimeMillis() - timerStart); + } - if (loggerResiliency.isLoggable(Level.FINER) && (attemptNumber >= connectRetryCount)) { - loggerResiliency - .finer(toString() + " Connection open - connection failed. Maximum connection retry count " - + connectRetryCount + " reached."); - } + sqlServerError = e.getSQLServerError(); + + if (isFatalError(e) // do not retry on fatal errors + || timerHasExpired(timerExpire) // no time left + || (timerRemaining(timerExpire) < TimeUnit.SECONDS.toMillis(connectRetryInterval) + + 2 * timeForFirstTry) // not enough time for another retry + || (connectRetryCount == 0 && !isDBMirroring && !useTnir) // retries disabled + // retry at least once for TNIR and failover + || (connectRetryCount == 0 && (isDBMirroring || useTnir) && attemptNumber > 0) + || (connectRetryCount != 0 && attemptNumber >= connectRetryCount) // no retries left + ) { + if (loggerResiliency.isLoggable(Level.FINER)) { + logConnectFailure(attemptNumber, e, sqlServerError); + } - // estimate time it took to do 1 try - if (attemptNumber == 0) { - timeForFirstTry = (System.currentTimeMillis() - timerStart); - } + // close the connection and throw the error back + close(); + throw e; + } else { + if (loggerResiliency.isLoggable(Level.FINER)) { + logConnectFailure(attemptNumber, e, sqlServerError); + } - sqlServerError = e.getSQLServerError(); + // Close the TDS channel from the failed connection attempt so that we don't + // hold onto network resources any longer than necessary. + if (null != tdsChannel) + tdsChannel.close(); + } - if (isFatalError(e) // do not retry on fatal errors - || timerHasExpired(timerExpire) // no time left - || (timerRemaining(timerExpire) < TimeUnit.SECONDS.toMillis(connectRetryInterval) - + 2 * timeForFirstTry) // not enough time for another retry - || (connectRetryCount == 0 && !isDBMirroring && !useTnir) // retries disabled - // retry at least once for TNIR and failover - || (connectRetryCount == 0 && (isDBMirroring || useTnir) && attemptNumber > 0) - || (connectRetryCount != 0 && attemptNumber >= connectRetryCount) // no retries left - ) { - if (loggerResiliency.isLoggable(Level.FINER)) { - logConnectFailure(attemptNumber, e, sqlServerError); - } + // For standard connections and MultiSubnetFailover connections, change the + // sleep interval after every + // attempt. + // For DB Mirroring, we only sleep after every other attempt. + if (!isDBMirroring || 1 == attemptNumber % 2) { + // Check sleep interval to make sure we won't exceed the timeout + // Do this in the catch block so we can re-throw the current exception + long remainingMilliseconds = timerRemaining(timerExpire); + if (remainingMilliseconds <= fedauthRetryInterval) { - // close the connection and throw the error back - close(); - throw e; - } else { - if (loggerResiliency.isLoggable(Level.FINER)) { - logConnectFailure(attemptNumber, e, sqlServerError); + if (loggerResiliency.isLoggable(Level.FINER)) { + logConnectFailure(attemptNumber, e, sqlServerError); + } + + throw e; + } + } } - // Close the TDS channel from the failed connection attempt so that we don't - // hold onto network resources any longer than necessary. - if (null != tdsChannel) - tdsChannel.close(); - } + // We only get here when we failed to connect, but are going to re-try + // After trying to connect to both servers fails, sleep for a bit to prevent + // clogging + // the network with requests, then update sleep interval for next iteration (max + // 1 second interval) + // We have to sleep for every attempt in case of non-dbMirroring scenarios + // (including multisubnetfailover), + // Whereas for dbMirroring, we sleep for every two attempts as each attempt is + // to a different server. + // Make sure there's enough time to do another retry + if (!isDBMirroring || (isDBMirroring && (0 == attemptNumber % 2)) + && (attemptNumber < connectRetryCount && connectRetryCount != 0) && timerRemaining( + timerExpire) > (TimeUnit.SECONDS.toMillis(connectRetryInterval) + + 2 * timeForFirstTry)) { + + // don't wait for TNIR + if (!(useTnir && attemptNumber == 0)) { + if (loggerResiliency.isLoggable(Level.FINER)) { + loggerResiliency + .finer(toString() + " Connection open - connection failed on transient error " + + (sqlServerError != null ? sqlServerError.getErrorNumber() : "") + + ". Wait for connectRetryInterval(" + connectRetryInterval + + ")s before retry #" + + attemptNumber); + } - // For standard connections and MultiSubnetFailover connections, change the sleep interval after every - // attempt. - // For DB Mirroring, we only sleep after every other attempt. - if (!isDBMirroring || 1 == attemptNumber % 2) { - // Check sleep interval to make sure we won't exceed the timeout - // Do this in the catch block so we can re-throw the current exception - long remainingMilliseconds = timerRemaining(timerExpire); - if (remainingMilliseconds <= fedauthRetryInterval) { + sleepForInterval(TimeUnit.SECONDS.toMillis(connectRetryInterval)); + } + } - if (loggerResiliency.isLoggable(Level.FINER)) { - logConnectFailure(attemptNumber, e, sqlServerError); + // Update timeout interval (but no more than the point where we're supposed to + // fail: timerExpire) + attemptNumber++; + + if (useParallel) { + intervalExpire = System.currentTimeMillis() + (timeoutUnitInterval * (attemptNumber + 1)); + } else if (isDBMirroring) { + intervalExpire = System.currentTimeMillis() + (timeoutUnitInterval * ((attemptNumber / 2) + 1)); + } else if (useTnir) { + long timeSlice = timeoutUnitInterval * (1 << attemptNumber); + + // In case the timeout for the first slice is less than 500 ms then bump it up + // to 500 ms + if ((1 == attemptNumber) && (500 > timeSlice)) { + timeSlice = 500; } - throw e; + intervalExpire = System.currentTimeMillis() + timeSlice; + } else + intervalExpire = timerExpire; + // Due to the below condition and the timerHasExpired check in catch block, + // the multiSubnetFailover case or any other standardLogin case where + // timeOutInterval is full timeout would + // also be handled correctly. + if (intervalExpire > timerExpire) { + intervalExpire = timerExpire; } - } - } - // We only get here when we failed to connect, but are going to re-try - // After trying to connect to both servers fails, sleep for a bit to prevent clogging - // the network with requests, then update sleep interval for next iteration (max 1 second interval) - // We have to sleep for every attempt in case of non-dbMirroring scenarios (including multisubnetfailover), - // Whereas for dbMirroring, we sleep for every two attempts as each attempt is to a different server. - // Make sure there's enough time to do another retry - if (!isDBMirroring || (isDBMirroring && (0 == attemptNumber % 2)) - && (attemptNumber < connectRetryCount && connectRetryCount != 0) && timerRemaining( - timerExpire) > (TimeUnit.SECONDS.toMillis(connectRetryInterval) + 2 * timeForFirstTry)) { - - // don't wait for TNIR - if (!(useTnir && attemptNumber == 0)) { - if (loggerResiliency.isLoggable(Level.FINER)) { - loggerResiliency.finer(toString() + " Connection open - connection failed on transient error " - + (sqlServerError != null ? sqlServerError.getErrorNumber() : "") - + ". Wait for connectRetryInterval(" + connectRetryInterval + ")s before retry #" - + attemptNumber); + // try again, this time swapping primary/secondary servers + if (isDBMirroring) { + useFailoverHost = !useFailoverHost; } - - sleepForInterval(TimeUnit.SECONDS.toMillis(connectRetryInterval)); } - } - - // Update timeout interval (but no more than the point where we're supposed to fail: timerExpire) - attemptNumber++; - if (useParallel) { - intervalExpire = System.currentTimeMillis() + (timeoutUnitInterval * (attemptNumber + 1)); - } else if (isDBMirroring) { - intervalExpire = System.currentTimeMillis() + (timeoutUnitInterval * ((attemptNumber / 2) + 1)); - } else if (useTnir) { - long timeSlice = timeoutUnitInterval * (1 << attemptNumber); - - // In case the timeout for the first slice is less than 500 ms then bump it up to 500 ms - if ((1 == attemptNumber) && (500 > timeSlice)) { - timeSlice = 500; + // If we get here, connection/login succeeded! Just a few more checks & + // record-keeping + // if connected to failover host, but said host doesn't have DbMirroring set up, + // throw an error + if (useFailoverHost && null == failoverPartnerServerProvided) { + String curserverinfo = currentConnectPlaceHolder.getServerName(); + if (null != currentFOPlaceHolder.getInstanceName()) { + curserverinfo = curserverinfo + "\\"; + curserverinfo = curserverinfo + currentFOPlaceHolder.getInstanceName(); + } + MessageFormat form = new MessageFormat( + SQLServerException.getErrString("R_invalidPartnerConfiguration")); + Object[] msgArgs = { + activeConnectionProperties + .getProperty(SQLServerDriverStringProperty.DATABASE_NAME.toString()), + curserverinfo }; + terminate(SQLServerException.DRIVER_ERROR_UNSUPPORTED_CONFIG, form.format(msgArgs)); } - intervalExpire = System.currentTimeMillis() + timeSlice; - } else - intervalExpire = timerExpire; - // Due to the below condition and the timerHasExpired check in catch block, - // the multiSubnetFailover case or any other standardLogin case where timeOutInterval is full timeout would - // also be handled correctly. - if (intervalExpire > timerExpire) { - intervalExpire = timerExpire; - } - - // try again, this time swapping primary/secondary servers - if (isDBMirroring) { - useFailoverHost = !useFailoverHost; - } - } - - // If we get here, connection/login succeeded! Just a few more checks & record-keeping - // if connected to failover host, but said host doesn't have DbMirroring set up, throw an error - if (useFailoverHost && null == failoverPartnerServerProvided) { - String curserverinfo = currentConnectPlaceHolder.getServerName(); - if (null != currentFOPlaceHolder.getInstanceName()) { - curserverinfo = curserverinfo + "\\"; - curserverinfo = curserverinfo + currentFOPlaceHolder.getInstanceName(); - } - MessageFormat form = new MessageFormat(SQLServerException.getErrString("R_invalidPartnerConfiguration")); - Object[] msgArgs = { - activeConnectionProperties.getProperty(SQLServerDriverStringProperty.DATABASE_NAME.toString()), - curserverinfo}; - terminate(SQLServerException.DRIVER_ERROR_UNSUPPORTED_CONFIG, form.format(msgArgs)); - } + if (null != failoverPartnerServerProvided) { + // if server returns failoverPartner when multiSubnetFailover keyword is used, + // fail + if (multiSubnetFailover) { + String msg = SQLServerException.getErrString("R_dbMirroringWithMultiSubnetFailover"); + terminate(SQLServerException.DRIVER_ERROR_UNSUPPORTED_CONFIG, msg); + } - if (null != failoverPartnerServerProvided) { - // if server returns failoverPartner when multiSubnetFailover keyword is used, fail - if (multiSubnetFailover) { - String msg = SQLServerException.getErrString("R_dbMirroringWithMultiSubnetFailover"); - terminate(SQLServerException.DRIVER_ERROR_UNSUPPORTED_CONFIG, msg); - } + // if server returns failoverPartner and applicationIntent=ReadOnly, fail + if ((applicationIntent != null) && applicationIntent.equals(ApplicationIntent.READ_ONLY)) { + String msg = SQLServerException.getErrString("R_dbMirroringWithReadOnlyIntent"); + terminate(SQLServerException.DRIVER_ERROR_UNSUPPORTED_CONFIG, msg); + } - // if server returns failoverPartner and applicationIntent=ReadOnly, fail - if ((applicationIntent != null) && applicationIntent.equals(ApplicationIntent.READ_ONLY)) { - String msg = SQLServerException.getErrString("R_dbMirroringWithReadOnlyIntent"); - terminate(SQLServerException.DRIVER_ERROR_UNSUPPORTED_CONFIG, msg); - } + if (null == tempFailover) + tempFailover = new FailoverInfo(failoverPartnerServerProvided, false); + // if the failover is not from the map already out this in the map, if it is + // from the map just make sure + // that we change the + if (null != foActual) { + // We must wait for CompleteLogin to finish for to have the + // env change from the server to know its designated failover + // partner; saved in failoverPartnerServerProvided + foActual.failoverAdd(this, useFailoverHost, failoverPartnerServerProvided); + } else { + String databaseNameProperty = SQLServerDriverStringProperty.DATABASE_NAME.toString(); + String instanceNameProperty = SQLServerDriverStringProperty.INSTANCE_NAME.toString(); + String serverNameProperty = SQLServerDriverStringProperty.SERVER_NAME.toString(); - if (null == tempFailover) - tempFailover = new FailoverInfo(failoverPartnerServerProvided, false); - // if the failover is not from the map already out this in the map, if it is from the map just make sure - // that we change the - if (null != foActual) { - // We must wait for CompleteLogin to finish for to have the - // env change from the server to know its designated failover - // partner; saved in failoverPartnerServerProvided - foActual.failoverAdd(this, useFailoverHost, failoverPartnerServerProvided); - } else { - String databaseNameProperty = SQLServerDriverStringProperty.DATABASE_NAME.toString(); - String instanceNameProperty = SQLServerDriverStringProperty.INSTANCE_NAME.toString(); - String serverNameProperty = SQLServerDriverStringProperty.SERVER_NAME.toString(); + if (connectionlogger.isLoggable(Level.FINE)) { + connectionlogger.fine(toString() + " adding new failover info server: " + + activeConnectionProperties.getProperty(serverNameProperty) + " instance: " + + activeConnectionProperties.getProperty(instanceNameProperty) + " database: " + + activeConnectionProperties.getProperty(databaseNameProperty) + + " server provided failover: " + failoverPartnerServerProvided); + } - if (connectionlogger.isLoggable(Level.FINE)) { - connectionlogger.fine(toString() + " adding new failover info server: " - + activeConnectionProperties.getProperty(serverNameProperty) + " instance: " - + activeConnectionProperties.getProperty(instanceNameProperty) + " database: " - + activeConnectionProperties.getProperty(databaseNameProperty) - + " server provided failover: " + failoverPartnerServerProvided); + tempFailover.failoverAdd(this, useFailoverHost, failoverPartnerServerProvided); + FailoverMapSingleton.putFailoverInfo(this, primary, + activeConnectionProperties.getProperty(instanceNameProperty), + activeConnectionProperties.getProperty(databaseNameProperty), tempFailover, + useFailoverHost, + failoverPartnerServerProvided); + } } - tempFailover.failoverAdd(this, useFailoverHost, failoverPartnerServerProvided); - FailoverMapSingleton.putFailoverInfo(this, primary, - activeConnectionProperties.getProperty(instanceNameProperty), - activeConnectionProperties.getProperty(databaseNameProperty), tempFailover, useFailoverHost, - failoverPartnerServerProvided); + } catch (Exception e) { + loginScope.setException(e); + throw e; } } } @@ -4262,407 +4318,452 @@ private void executeReconnect(LogonCommand logonCommand) throws SQLServerExcepti * Negotiates prelogin information with the server. */ void prelogin(String serverName, int portNumber) throws SQLServerException { - // Build a TDS Pre-Login packet to send to the server. - if ((!authenticationString.equalsIgnoreCase(SqlAuthentication.NOT_SPECIFIED.toString())) - || (null != accessTokenInByte) || null != accessTokenCallback || hasAccessTokenCallbackClass) { - fedAuthRequiredByUser = true; - } - - // Message length (including header) - final byte messageLength; - final byte fedAuthOffset; - if (fedAuthRequiredByUser) { - messageLength = TDS.B_PRELOGIN_MESSAGE_LENGTH_WITH_FEDAUTH; - if (encryptOption.compareToIgnoreCase(EncryptOption.STRICT.toString()) == 0) { - requestedEncryptionLevel = TDS.ENCRYPT_NOT_SUP; - } else { - requestedEncryptionLevel = TDS.ENCRYPT_ON; - } - - // since we added one more line for prelogin option with fedauth, - // we also needed to modify the offsets above, by adding 5 to each offset, - // since the data session of each option is push 5 bytes behind. - fedAuthOffset = 5; - } else { - messageLength = TDS.B_PRELOGIN_MESSAGE_LENGTH; - fedAuthOffset = 0; - } - - final byte[] preloginRequest = new byte[messageLength]; - - int preloginRequestOffset = 0; - - byte[] bufferHeader = { - // Buffer Header - TDS.PKT_PRELOGIN, // Message Type - TDS.STATUS_BIT_EOM, 0, messageLength, 0, 0, // SPID (not used) - 0, // Packet (not used) - 0, // Window (not used) - }; - - System.arraycopy(bufferHeader, 0, preloginRequest, preloginRequestOffset, bufferHeader.length); - preloginRequestOffset = preloginRequestOffset + bufferHeader.length; - - byte[] preloginOptionsBeforeFedAuth = { - // OPTION_TOKEN (BYTE), OFFSET (USHORT), LENGTH (USHORT) - TDS.B_PRELOGIN_OPTION_VERSION, 0, (byte) (16 + fedAuthOffset), 0, 6, // UL_VERSION + US_SUBBUILD - TDS.B_PRELOGIN_OPTION_ENCRYPTION, 0, (byte) (22 + fedAuthOffset), 0, 1, // B_FENCRYPTION - TDS.B_PRELOGIN_OPTION_TRACEID, 0, (byte) (23 + fedAuthOffset), 0, 36, // ClientConnectionId + ActivityId - }; - System.arraycopy(preloginOptionsBeforeFedAuth, 0, preloginRequest, preloginRequestOffset, - preloginOptionsBeforeFedAuth.length); - preloginRequestOffset = preloginRequestOffset + preloginOptionsBeforeFedAuth.length; - - if (fedAuthRequiredByUser) { - byte[] preloginOptions2 = {TDS.B_PRELOGIN_OPTION_FEDAUTHREQUIRED, 0, 64, 0, 1,}; - System.arraycopy(preloginOptions2, 0, preloginRequest, preloginRequestOffset, preloginOptions2.length); - preloginRequestOffset = preloginRequestOffset + preloginOptions2.length; - } - - preloginRequest[preloginRequestOffset] = TDS.B_PRELOGIN_OPTION_TERMINATOR; - preloginRequestOffset++; - - // PL_OPTION_DATA - byte[] preloginOptionData = { - // Driver major and minor version, 1 byte each - (byte) SQLJdbcVersion.MAJOR, (byte) SQLJdbcVersion.MINOR, - // Revision (Big Endian), 2 bytes - (byte) ((SQLJdbcVersion.PATCH & 0xff00) >> 8), (byte) (SQLJdbcVersion.PATCH & 0xff), - // Build (Little Endian), 2 bytes - (byte) (SQLJdbcVersion.BUILD & 0xff), (byte) ((SQLJdbcVersion.BUILD & 0xff00) >> 8), - - // Encryption - // turn encryption off for TDS 8 since it's already enabled - (null == clientCertificate) ? requestedEncryptionLevel - : (byte) (requestedEncryptionLevel | TDS.ENCRYPT_CLIENT_CERT), - - // TRACEID Data Session (ClientConnectionId + ActivityId) - Initialize to 0 - 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, - 0,}; - System.arraycopy(preloginOptionData, 0, preloginRequest, preloginRequestOffset, preloginOptionData.length); - preloginRequestOffset = preloginRequestOffset + preloginOptionData.length; - - // If the client's PRELOGIN request message contains the FEDAUTHREQUIRED option, - // the client MUST specify 0x01 as the B_FEDAUTHREQUIRED value - if (fedAuthRequiredByUser) { - preloginRequest[preloginRequestOffset] = 1; - preloginRequestOffset = preloginRequestOffset + 1; - } - - final byte[] preloginResponse = new byte[TDS.INITIAL_PACKET_SIZE]; - String preloginErrorLogString = " Prelogin error: host " + serverName + " port " + portNumber; - - final byte[] conIdByteArray = Util.asGuidByteArray(clientConnectionId); - - int offset; - - if (fedAuthRequiredByUser) { - offset = preloginRequest.length - 36 - 1; // point to the TRACEID Data Session (one more byte for fedauth - // data session) - } else { - offset = preloginRequest.length - 36; // point to the TRACEID Data Session - } - - // copy ClientConnectionId - System.arraycopy(conIdByteArray, 0, preloginRequest, offset, conIdByteArray.length); - offset += conIdByteArray.length; - - ActivityId activityId = ActivityCorrelator.getNext(); - final byte[] actIdByteArray = Util.asGuidByteArray(activityId.getId()); - System.arraycopy(actIdByteArray, 0, preloginRequest, offset, actIdByteArray.length); - offset += actIdByteArray.length; - long seqNum = activityId.getSequence(); - Util.writeInt((int) seqNum, preloginRequest, offset); - offset += 4; - - if (Util.isActivityTraceOn() && connectionlogger.isLoggable(Level.FINER)) { - connectionlogger.finer(toString() + " ActivityId " + activityId); - } - - if (connectionlogger.isLoggable(Level.FINER)) { - connectionlogger.finer( - toString() + " Requesting encryption level:" + TDS.getEncryptionLevel(requestedEncryptionLevel)); - } - - // Write the entire prelogin request - if (tdsChannel.isLoggingPackets()) - tdsChannel.logPacket(preloginRequest, 0, preloginRequest.length, toString() + " Prelogin request"); - - try { - tdsChannel.write(preloginRequest, 0, preloginRequest.length); - tdsChannel.flush(); - } catch (SQLServerException e) { - connectionlogger.warning( - toString() + preloginErrorLogString + " Error sending prelogin request: " + e.getMessage()); - throw e; - } - - // Read the entire prelogin response - int responseLength = preloginResponse.length; - int responseBytesRead = 0; - boolean processedResponseHeader = false; - while (responseBytesRead < responseLength) { - int bytesRead; - + try (PerformanceLog.Scope preLoginScope = PerformanceLog.createScope(PerformanceLog.perfLoggerConnection, + traceID, PerformanceActivity.PRELOGIN)) { try { - bytesRead = tdsChannel.read(preloginResponse, responseBytesRead, responseLength - responseBytesRead); - } catch (SQLServerException e) { - connectionlogger.warning( - toString() + preloginErrorLogString + " Error reading prelogin response: " + e.getMessage()); - throw e; - } - - // If we reached EOF before the end of the prelogin response then something is wrong. - // - // Special case: If there was no response at all (i.e. the server closed the connection), - // then maybe we are just trying to talk to an older server that doesn't support prelogin - // (and that we don't support with this driver). - if (-1 == bytesRead) { - if (connectionlogger.isLoggable(Level.WARNING)) { - connectionlogger.warning(toString() + preloginErrorLogString - + " Unexpected end of prelogin response after " + responseBytesRead + " bytes read"); - } - MessageFormat form = new MessageFormat(SQLServerException.getErrString("R_tcpipConnectionFailed")); - Object[] msgArgs = {getServerNameString(serverName), Integer.toString(portNumber), - SQLServerException.getErrString("R_notSQLServer")}; - terminate(SQLServerException.DRIVER_ERROR_IO_FAILED, form.format(msgArgs)); - } - - // Otherwise, we must have read some bytes... - assert bytesRead >= 0; - assert bytesRead <= responseLength - responseBytesRead; - - if (tdsChannel.isLoggingPackets()) - tdsChannel.logPacket(preloginResponse, responseBytesRead, bytesRead, toString() + " Prelogin response"); - - responseBytesRead += bytesRead; - - // Validate the response header if we haven't already done so and - // we've read enough of the response to do it. - if (!processedResponseHeader && responseBytesRead >= TDS.PACKET_HEADER_SIZE) { - // Verify that the response is actually a response... - if (TDS.PKT_REPLY != preloginResponse[0]) { - if (connectionlogger.isLoggable(Level.WARNING)) { - connectionlogger.warning(toString() + preloginErrorLogString + " Unexpected response type:" - + preloginResponse[0]); - } - MessageFormat form = new MessageFormat(SQLServerException.getErrString("R_tcpipConnectionFailed")); - Object[] msgArgs = {getServerNameString(serverName), Integer.toString(portNumber), - SQLServerException.getErrString("R_notSQLServer")}; - terminate(SQLServerException.DRIVER_ERROR_IO_FAILED, form.format(msgArgs)); + // Build a TDS Pre-Login packet to send to the server. + if ((!authenticationString.equalsIgnoreCase(SqlAuthentication.NOT_SPECIFIED.toString())) + || (null != accessTokenInByte) || null != accessTokenCallback || hasAccessTokenCallbackClass) { + fedAuthRequiredByUser = true; } - // Verify that the response claims to only be one TDS packet long. - // In theory, it can be longer, but in current practice it isn't, as all of the - // prelogin response items easily fit into a single 4K packet. - if (TDS.STATUS_BIT_EOM != (TDS.STATUS_BIT_EOM & preloginResponse[1])) { - if (connectionlogger.isLoggable(Level.WARNING)) { - connectionlogger.warning(toString() + preloginErrorLogString + " Unexpected response status:" - + preloginResponse[1]); + // Message length (including header) + final byte messageLength; + final byte fedAuthOffset; + if (fedAuthRequiredByUser) { + messageLength = TDS.B_PRELOGIN_MESSAGE_LENGTH_WITH_FEDAUTH; + if (encryptOption.compareToIgnoreCase(EncryptOption.STRICT.toString()) == 0) { + requestedEncryptionLevel = TDS.ENCRYPT_NOT_SUP; + } else { + requestedEncryptionLevel = TDS.ENCRYPT_ON; } - MessageFormat form = new MessageFormat(SQLServerException.getErrString("R_tcpipConnectionFailed")); - Object[] msgArgs = {getServerNameString(serverName), Integer.toString(portNumber), - SQLServerException.getErrString("R_notSQLServer")}; - terminate(SQLServerException.DRIVER_ERROR_IO_FAILED, form.format(msgArgs)); - } - // Verify that the length of the response claims to be small enough to fit in the allocated area - responseLength = Util.readUnsignedShortBigEndian(preloginResponse, 2); - assert responseLength >= 0; - - if (responseLength >= preloginResponse.length) { - if (connectionlogger.isLoggable(Level.WARNING)) { - connectionlogger.warning(toString() + preloginErrorLogString + " Response length:" - + responseLength + " is greater than allowed length:" + preloginResponse.length); - } - MessageFormat form = new MessageFormat(SQLServerException.getErrString("R_tcpipConnectionFailed")); - Object[] msgArgs = {getServerNameString(serverName), Integer.toString(portNumber), - SQLServerException.getErrString("R_notSQLServer")}; - terminate(SQLServerException.DRIVER_ERROR_IO_FAILED, form.format(msgArgs)); + // since we added one more line for prelogin option with fedauth, + // we also needed to modify the offsets above, by adding 5 to each offset, + // since the data session of each option is push 5 bytes behind. + fedAuthOffset = 5; + } else { + messageLength = TDS.B_PRELOGIN_MESSAGE_LENGTH; + fedAuthOffset = 0; + } + + final byte[] preloginRequest = new byte[messageLength]; + + int preloginRequestOffset = 0; + + byte[] bufferHeader = { + // Buffer Header + TDS.PKT_PRELOGIN, // Message Type + TDS.STATUS_BIT_EOM, 0, messageLength, 0, 0, // SPID (not used) + 0, // Packet (not used) + 0, // Window (not used) + }; + + System.arraycopy(bufferHeader, 0, preloginRequest, preloginRequestOffset, bufferHeader.length); + preloginRequestOffset = preloginRequestOffset + bufferHeader.length; + + byte[] preloginOptionsBeforeFedAuth = { + // OPTION_TOKEN (BYTE), OFFSET (USHORT), LENGTH (USHORT) + TDS.B_PRELOGIN_OPTION_VERSION, 0, (byte) (16 + fedAuthOffset), 0, 6, // UL_VERSION + US_SUBBUILD + TDS.B_PRELOGIN_OPTION_ENCRYPTION, 0, (byte) (22 + fedAuthOffset), 0, 1, // B_FENCRYPTION + TDS.B_PRELOGIN_OPTION_TRACEID, 0, (byte) (23 + fedAuthOffset), 0, 36, // ClientConnectionId + + // ActivityId + }; + System.arraycopy(preloginOptionsBeforeFedAuth, 0, preloginRequest, preloginRequestOffset, + preloginOptionsBeforeFedAuth.length); + preloginRequestOffset = preloginRequestOffset + preloginOptionsBeforeFedAuth.length; + + if (fedAuthRequiredByUser) { + byte[] preloginOptions2 = { TDS.B_PRELOGIN_OPTION_FEDAUTHREQUIRED, 0, 64, 0, 1, }; + System.arraycopy(preloginOptions2, 0, preloginRequest, preloginRequestOffset, + preloginOptions2.length); + preloginRequestOffset = preloginRequestOffset + preloginOptions2.length; + } + + preloginRequest[preloginRequestOffset] = TDS.B_PRELOGIN_OPTION_TERMINATOR; + preloginRequestOffset++; + + // PL_OPTION_DATA + byte[] preloginOptionData = { + // Driver major and minor version, 1 byte each + (byte) SQLJdbcVersion.MAJOR, (byte) SQLJdbcVersion.MINOR, + // Revision (Big Endian), 2 bytes + (byte) ((SQLJdbcVersion.PATCH & 0xff00) >> 8), (byte) (SQLJdbcVersion.PATCH & 0xff), + // Build (Little Endian), 2 bytes + (byte) (SQLJdbcVersion.BUILD & 0xff), (byte) ((SQLJdbcVersion.BUILD & 0xff00) >> 8), + + // Encryption + // turn encryption off for TDS 8 since it's already enabled + (null == clientCertificate) ? requestedEncryptionLevel + : (byte) (requestedEncryptionLevel | TDS.ENCRYPT_CLIENT_CERT), + + // TRACEID Data Session (ClientConnectionId + ActivityId) - Initialize to 0 + 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, + 0, 0, 0, + 0, }; + System.arraycopy(preloginOptionData, 0, preloginRequest, preloginRequestOffset, + preloginOptionData.length); + preloginRequestOffset = preloginRequestOffset + preloginOptionData.length; + + // If the client's PRELOGIN request message contains the FEDAUTHREQUIRED option, + // the client MUST specify 0x01 as the B_FEDAUTHREQUIRED value + if (fedAuthRequiredByUser) { + preloginRequest[preloginRequestOffset] = 1; + preloginRequestOffset = preloginRequestOffset + 1; + } + + final byte[] preloginResponse = new byte[TDS.INITIAL_PACKET_SIZE]; + String preloginErrorLogString = " Prelogin error: host " + serverName + " port " + portNumber; + + final byte[] conIdByteArray = Util.asGuidByteArray(clientConnectionId); + + int offset; + + if (fedAuthRequiredByUser) { + offset = preloginRequest.length - 36 - 1; // point to the TRACEID Data Session (one more byte for + // fedauth + // data session) + } else { + offset = preloginRequest.length - 36; // point to the TRACEID Data Session } - processedResponseHeader = true; - } - } + // copy ClientConnectionId + System.arraycopy(conIdByteArray, 0, preloginRequest, offset, conIdByteArray.length); + offset += conIdByteArray.length; - // Walk the response for prelogin options received. We expect at least to get - // back the server version and the encryption level. - boolean receivedVersionOption = false; - negotiatedEncryptionLevel = TDS.ENCRYPT_INVALID; + ActivityId activityId = ActivityCorrelator.getNext(); + final byte[] actIdByteArray = Util.asGuidByteArray(activityId.getId()); + System.arraycopy(actIdByteArray, 0, preloginRequest, offset, actIdByteArray.length); + offset += actIdByteArray.length; + long seqNum = activityId.getSequence(); + Util.writeInt((int) seqNum, preloginRequest, offset); + offset += 4; - int responseIndex = TDS.PACKET_HEADER_SIZE; - while (true) { - // Get the option token - if (responseIndex >= responseLength) { - if (connectionlogger.isLoggable(Level.WARNING)) { - connectionlogger.warning(toString() + " Option token not found"); + if (Util.isActivityTraceOn() && connectionlogger.isLoggable(Level.FINER)) { + connectionlogger.finer(toString() + " ActivityId " + activityId); } - throwInvalidTDS(); - } - byte optionToken = preloginResponse[responseIndex++]; - - // When we reach the option terminator, we're done processing option tokens - if (TDS.B_PRELOGIN_OPTION_TERMINATOR == optionToken) - break; - // Get the offset and length that follows the option token - if (responseIndex + 4 >= responseLength) { - if (connectionlogger.isLoggable(Level.WARNING)) { - connectionlogger.warning(toString() + " Offset/Length not found for option:" + optionToken); + if (connectionlogger.isLoggable(Level.FINER)) { + connectionlogger.finer( + toString() + " Requesting encryption level:" + + TDS.getEncryptionLevel(requestedEncryptionLevel)); } - throwInvalidTDS(); - } - - int optionOffset = Util.readUnsignedShortBigEndian(preloginResponse, responseIndex) - + TDS.PACKET_HEADER_SIZE; - responseIndex += 2; - assert optionOffset >= 0; - int optionLength = Util.readUnsignedShortBigEndian(preloginResponse, responseIndex); - responseIndex += 2; - assert optionLength >= 0; + // Write the entire prelogin request + if (tdsChannel.isLoggingPackets()) + tdsChannel.logPacket(preloginRequest, 0, preloginRequest.length, toString() + " Prelogin request"); - if (optionOffset + optionLength > responseLength) { - if (connectionlogger.isLoggable(Level.WARNING)) { - connectionlogger.warning(toString() + " Offset:" + optionOffset + " and length:" + optionLength - + " exceed response length:" + responseLength); + try { + tdsChannel.write(preloginRequest, 0, preloginRequest.length); + tdsChannel.flush(); + } catch (SQLServerException e) { + connectionlogger.warning( + toString() + preloginErrorLogString + " Error sending prelogin request: " + e.getMessage()); + throw e; } - throwInvalidTDS(); - } - switch (optionToken) { - case TDS.B_PRELOGIN_OPTION_VERSION: - if (receivedVersionOption) { - if (connectionlogger.isLoggable(Level.WARNING)) { - connectionlogger.warning(toString() + " Version option already received"); - } - throwInvalidTDS(); - } + // Read the entire prelogin response + int responseLength = preloginResponse.length; + int responseBytesRead = 0; + boolean processedResponseHeader = false; + while (responseBytesRead < responseLength) { + int bytesRead; - if (6 != optionLength) { - if (connectionlogger.isLoggable(Level.WARNING)) { - connectionlogger.warning(toString() + " Version option length:" + optionLength - + " is incorrect. Correct value is 6."); - } - throwInvalidTDS(); + try { + bytesRead = tdsChannel.read(preloginResponse, responseBytesRead, + responseLength - responseBytesRead); + } catch (SQLServerException e) { + connectionlogger.warning( + toString() + preloginErrorLogString + " Error reading prelogin response: " + + e.getMessage()); + throw e; } - serverMajorVersion = preloginResponse[optionOffset]; - if (serverMajorVersion < 9) { + // If we reached EOF before the end of the prelogin response then something is + // wrong. + // + // Special case: If there was no response at all (i.e. the server closed the + // connection), + // then maybe we are just trying to talk to an older server that doesn't support + // prelogin + // (and that we don't support with this driver). + if (-1 == bytesRead) { if (connectionlogger.isLoggable(Level.WARNING)) { - connectionlogger.warning(toString() + " Server major version:" + serverMajorVersion - + " is not supported by this driver."); + connectionlogger.warning(toString() + preloginErrorLogString + + " Unexpected end of prelogin response after " + responseBytesRead + + " bytes read"); } MessageFormat form = new MessageFormat( - SQLServerException.getErrString("R_unsupportedServerVersion")); - Object[] msgArgs = {Integer.toString(preloginResponse[optionOffset])}; - terminate(SQLServerException.DRIVER_ERROR_UNSUPPORTED_CONFIG, form.format(msgArgs)); + SQLServerException.getErrString("R_tcpipConnectionFailed")); + Object[] msgArgs = { getServerNameString(serverName), Integer.toString(portNumber), + SQLServerException.getErrString("R_notSQLServer") }; + terminate(SQLServerException.DRIVER_ERROR_IO_FAILED, form.format(msgArgs)); } - if (connectionlogger.isLoggable(Level.FINE)) - connectionlogger - .fine(toString() + " Server returned major version:" + preloginResponse[optionOffset]); + // Otherwise, we must have read some bytes... + assert bytesRead >= 0; + assert bytesRead <= responseLength - responseBytesRead; - receivedVersionOption = true; - break; + if (tdsChannel.isLoggingPackets()) + tdsChannel.logPacket(preloginResponse, responseBytesRead, bytesRead, + toString() + " Prelogin response"); - case TDS.B_PRELOGIN_OPTION_ENCRYPTION: - if (TDS.ENCRYPT_INVALID != negotiatedEncryptionLevel) { - if (connectionlogger.isLoggable(Level.WARNING)) { - connectionlogger.warning(toString() + " Encryption option already received"); + responseBytesRead += bytesRead; + + // Validate the response header if we haven't already done so and + // we've read enough of the response to do it. + if (!processedResponseHeader && responseBytesRead >= TDS.PACKET_HEADER_SIZE) { + // Verify that the response is actually a response... + if (TDS.PKT_REPLY != preloginResponse[0]) { + if (connectionlogger.isLoggable(Level.WARNING)) { + connectionlogger + .warning(toString() + preloginErrorLogString + " Unexpected response type:" + + preloginResponse[0]); + } + MessageFormat form = new MessageFormat( + SQLServerException.getErrString("R_tcpipConnectionFailed")); + Object[] msgArgs = { getServerNameString(serverName), Integer.toString(portNumber), + SQLServerException.getErrString("R_notSQLServer") }; + terminate(SQLServerException.DRIVER_ERROR_IO_FAILED, form.format(msgArgs)); } - throwInvalidTDS(); + + // Verify that the response claims to only be one TDS packet long. + // In theory, it can be longer, but in current practice it isn't, as all of the + // prelogin response items easily fit into a single 4K packet. + if (TDS.STATUS_BIT_EOM != (TDS.STATUS_BIT_EOM & preloginResponse[1])) { + if (connectionlogger.isLoggable(Level.WARNING)) { + connectionlogger + .warning(toString() + preloginErrorLogString + " Unexpected response status:" + + preloginResponse[1]); + } + MessageFormat form = new MessageFormat( + SQLServerException.getErrString("R_tcpipConnectionFailed")); + Object[] msgArgs = { getServerNameString(serverName), Integer.toString(portNumber), + SQLServerException.getErrString("R_notSQLServer") }; + terminate(SQLServerException.DRIVER_ERROR_IO_FAILED, form.format(msgArgs)); + } + + // Verify that the length of the response claims to be small enough to fit in + // the allocated area + responseLength = Util.readUnsignedShortBigEndian(preloginResponse, 2); + assert responseLength >= 0; + + if (responseLength >= preloginResponse.length) { + if (connectionlogger.isLoggable(Level.WARNING)) { + connectionlogger.warning(toString() + preloginErrorLogString + " Response length:" + + responseLength + " is greater than allowed length:" + + preloginResponse.length); + } + MessageFormat form = new MessageFormat( + SQLServerException.getErrString("R_tcpipConnectionFailed")); + Object[] msgArgs = { getServerNameString(serverName), Integer.toString(portNumber), + SQLServerException.getErrString("R_notSQLServer") }; + terminate(SQLServerException.DRIVER_ERROR_IO_FAILED, form.format(msgArgs)); + } + + processedResponseHeader = true; } + } + + // Walk the response for prelogin options received. We expect at least to get + // back the server version and the encryption level. + boolean receivedVersionOption = false; + negotiatedEncryptionLevel = TDS.ENCRYPT_INVALID; - if (1 != optionLength) { + int responseIndex = TDS.PACKET_HEADER_SIZE; + while (true) { + // Get the option token + if (responseIndex >= responseLength) { if (connectionlogger.isLoggable(Level.WARNING)) { - connectionlogger.warning(toString() + " Encryption option length:" + optionLength - + " is incorrect. Correct value is 1."); + connectionlogger.warning(toString() + " Option token not found"); } throwInvalidTDS(); } + byte optionToken = preloginResponse[responseIndex++]; - negotiatedEncryptionLevel = preloginResponse[optionOffset]; + // When we reach the option terminator, we're done processing option tokens + if (TDS.B_PRELOGIN_OPTION_TERMINATOR == optionToken) + break; - // If the server did not return a valid encryption level, terminate the connection. - if (TDS.ENCRYPT_OFF != negotiatedEncryptionLevel && TDS.ENCRYPT_ON != negotiatedEncryptionLevel - && TDS.ENCRYPT_REQ != negotiatedEncryptionLevel - && TDS.ENCRYPT_NOT_SUP != negotiatedEncryptionLevel) { + // Get the offset and length that follows the option token + if (responseIndex + 4 >= responseLength) { if (connectionlogger.isLoggable(Level.WARNING)) { - connectionlogger.warning(toString() + " Server returned " - + TDS.getEncryptionLevel(negotiatedEncryptionLevel)); + connectionlogger.warning(toString() + " Offset/Length not found for option:" + optionToken); } throwInvalidTDS(); } - if (connectionlogger.isLoggable(Level.FINER)) - connectionlogger.finer(toString() + " Negotiated encryption level:" - + TDS.getEncryptionLevel(negotiatedEncryptionLevel)); - - // If we requested SSL encryption and the server does not support it, then terminate the connection. - if (TDS.ENCRYPT_ON == requestedEncryptionLevel && TDS.ENCRYPT_ON != negotiatedEncryptionLevel - && TDS.ENCRYPT_REQ != negotiatedEncryptionLevel) { - terminate(SQLServerException.DRIVER_ERROR_SSL_FAILED, - SQLServerException.getErrString("R_sslRequiredNoServerSupport")); - } + int optionOffset = Util.readUnsignedShortBigEndian(preloginResponse, responseIndex) + + TDS.PACKET_HEADER_SIZE; + responseIndex += 2; + assert optionOffset >= 0; - // If we say we don't support SSL and the server doesn't accept unencrypted connections, - // then terminate the connection. - if (TDS.ENCRYPT_NOT_SUP == requestedEncryptionLevel - && TDS.ENCRYPT_NOT_SUP != negotiatedEncryptionLevel && !isTDS8) { - // If the server required an encrypted connection then terminate with an appropriate error. - if (TDS.ENCRYPT_REQ == negotiatedEncryptionLevel) - terminate(SQLServerException.DRIVER_ERROR_SSL_FAILED, - SQLServerException.getErrString("R_sslRequiredByServer")); + int optionLength = Util.readUnsignedShortBigEndian(preloginResponse, responseIndex); + responseIndex += 2; + assert optionLength >= 0; + if (optionOffset + optionLength > responseLength) { if (connectionlogger.isLoggable(Level.WARNING)) { - connectionlogger.warning(toString() + " Client requested encryption level: " - + TDS.getEncryptionLevel(requestedEncryptionLevel) - + " Server returned unexpected encryption level: " - + TDS.getEncryptionLevel(negotiatedEncryptionLevel)); + connectionlogger + .warning(toString() + " Offset:" + optionOffset + " and length:" + optionLength + + " exceed response length:" + responseLength); } throwInvalidTDS(); } - break; - case TDS.B_PRELOGIN_OPTION_FEDAUTHREQUIRED: - // Only 0x00 and 0x01 are accepted values from the server. - if (0 != preloginResponse[optionOffset] && 1 != preloginResponse[optionOffset]) { - if (connectionlogger.isLoggable(Level.SEVERE)) { - connectionlogger.severe(toString() - + " Server sent an unexpected value for FedAuthRequired PreLogin Option. Value was " - + preloginResponse[optionOffset]); - } - MessageFormat form = new MessageFormat( - SQLServerException.getErrString("R_FedAuthRequiredPreLoginResponseInvalidValue")); - throw new SQLServerException(form.format(new Object[] {preloginResponse[optionOffset]}), null); - } + switch (optionToken) { + case TDS.B_PRELOGIN_OPTION_VERSION: + if (receivedVersionOption) { + if (connectionlogger.isLoggable(Level.WARNING)) { + connectionlogger.warning(toString() + " Version option already received"); + } + throwInvalidTDS(); + } + + if (6 != optionLength) { + if (connectionlogger.isLoggable(Level.WARNING)) { + connectionlogger.warning(toString() + " Version option length:" + optionLength + + " is incorrect. Correct value is 6."); + } + throwInvalidTDS(); + } + + serverMajorVersion = preloginResponse[optionOffset]; + if (serverMajorVersion < 9) { + if (connectionlogger.isLoggable(Level.WARNING)) { + connectionlogger.warning(toString() + " Server major version:" + serverMajorVersion + + " is not supported by this driver."); + } + MessageFormat form = new MessageFormat( + SQLServerException.getErrString("R_unsupportedServerVersion")); + Object[] msgArgs = { Integer.toString(preloginResponse[optionOffset]) }; + terminate(SQLServerException.DRIVER_ERROR_UNSUPPORTED_CONFIG, form.format(msgArgs)); + } + + if (connectionlogger.isLoggable(Level.FINE)) + connectionlogger + .fine(toString() + " Server returned major version:" + + preloginResponse[optionOffset]); + + receivedVersionOption = true; + break; + + case TDS.B_PRELOGIN_OPTION_ENCRYPTION: + if (TDS.ENCRYPT_INVALID != negotiatedEncryptionLevel) { + if (connectionlogger.isLoggable(Level.WARNING)) { + connectionlogger.warning(toString() + " Encryption option already received"); + } + throwInvalidTDS(); + } + + if (1 != optionLength) { + if (connectionlogger.isLoggable(Level.WARNING)) { + connectionlogger.warning(toString() + " Encryption option length:" + optionLength + + " is incorrect. Correct value is 1."); + } + throwInvalidTDS(); + } + + negotiatedEncryptionLevel = preloginResponse[optionOffset]; + + // If the server did not return a valid encryption level, terminate the + // connection. + if (TDS.ENCRYPT_OFF != negotiatedEncryptionLevel + && TDS.ENCRYPT_ON != negotiatedEncryptionLevel + && TDS.ENCRYPT_REQ != negotiatedEncryptionLevel + && TDS.ENCRYPT_NOT_SUP != negotiatedEncryptionLevel) { + if (connectionlogger.isLoggable(Level.WARNING)) { + connectionlogger.warning(toString() + " Server returned " + + TDS.getEncryptionLevel(negotiatedEncryptionLevel)); + } + throwInvalidTDS(); + } + + if (connectionlogger.isLoggable(Level.FINER)) + connectionlogger.finer(toString() + " Negotiated encryption level:" + + TDS.getEncryptionLevel(negotiatedEncryptionLevel)); + + // If we requested SSL encryption and the server does not support it, then + // terminate the connection. + if (TDS.ENCRYPT_ON == requestedEncryptionLevel + && TDS.ENCRYPT_ON != negotiatedEncryptionLevel + && TDS.ENCRYPT_REQ != negotiatedEncryptionLevel) { + terminate(SQLServerException.DRIVER_ERROR_SSL_FAILED, + SQLServerException.getErrString("R_sslRequiredNoServerSupport")); + } + + // If we say we don't support SSL and the server doesn't accept unencrypted + // connections, + // then terminate the connection. + if (TDS.ENCRYPT_NOT_SUP == requestedEncryptionLevel + && TDS.ENCRYPT_NOT_SUP != negotiatedEncryptionLevel && !isTDS8) { + // If the server required an encrypted connection then terminate with an + // appropriate error. + if (TDS.ENCRYPT_REQ == negotiatedEncryptionLevel) + terminate(SQLServerException.DRIVER_ERROR_SSL_FAILED, + SQLServerException.getErrString("R_sslRequiredByServer")); + + if (connectionlogger.isLoggable(Level.WARNING)) { + connectionlogger.warning(toString() + " Client requested encryption level: " + + TDS.getEncryptionLevel(requestedEncryptionLevel) + + " Server returned unexpected encryption level: " + + TDS.getEncryptionLevel(negotiatedEncryptionLevel)); + } + throwInvalidTDS(); + } + break; + + case TDS.B_PRELOGIN_OPTION_FEDAUTHREQUIRED: + // Only 0x00 and 0x01 are accepted values from the server. + if (0 != preloginResponse[optionOffset] && 1 != preloginResponse[optionOffset]) { + if (connectionlogger.isLoggable(Level.SEVERE)) { + connectionlogger.severe(toString() + + " Server sent an unexpected value for FedAuthRequired PreLogin Option. Value was " + + preloginResponse[optionOffset]); + } + MessageFormat form = new MessageFormat( + SQLServerException + .getErrString("R_FedAuthRequiredPreLoginResponseInvalidValue")); + throw new SQLServerException( + form.format(new Object[] { preloginResponse[optionOffset] }), null); + } - // We must NOT use the response for the FEDAUTHREQUIRED PreLogin option, if the connection string - // option - // was not using the new Authentication keyword or in other words, if Authentication=NOT_SPECIFIED - // Or AccessToken is not null, mean token based authentication is used. - if (((null != authenticationString) - && (!authenticationString.equalsIgnoreCase(SqlAuthentication.NOT_SPECIFIED.toString()))) - || (null != accessTokenInByte) || null != accessTokenCallback - || hasAccessTokenCallbackClass) { - fedAuthRequiredPreLoginResponse = (preloginResponse[optionOffset] == 1); + // We must NOT use the response for the FEDAUTHREQUIRED PreLogin option, if the + // connection string + // option + // was not using the new Authentication keyword or in other words, if + // Authentication=NOT_SPECIFIED + // Or AccessToken is not null, mean token based authentication is used. + if (((null != authenticationString) + && (!authenticationString + .equalsIgnoreCase(SqlAuthentication.NOT_SPECIFIED.toString()))) + || (null != accessTokenInByte) || null != accessTokenCallback + || hasAccessTokenCallbackClass) { + fedAuthRequiredPreLoginResponse = (preloginResponse[optionOffset] == 1); + } + break; + + default: + if (connectionlogger.isLoggable(Level.FINER)) + connectionlogger + .finer(toString() + " Ignoring prelogin response option:" + optionToken); + break; } - break; + } - default: - if (connectionlogger.isLoggable(Level.FINER)) - connectionlogger.finer(toString() + " Ignoring prelogin response option:" + optionToken); - break; - } - } + if (!receivedVersionOption || TDS.ENCRYPT_INVALID == negotiatedEncryptionLevel) { + if (connectionlogger.isLoggable(Level.WARNING)) { + connectionlogger + .warning( + toString() + " Prelogin response is missing version and/or encryption option."); + } + throwInvalidTDS(); + } - if (!receivedVersionOption || TDS.ENCRYPT_INVALID == negotiatedEncryptionLevel) { - if (connectionlogger.isLoggable(Level.WARNING)) { - connectionlogger - .warning(toString() + " Prelogin response is missing version and/or encryption option."); + } catch (Exception e) { + preLoginScope.setException(e); + throw e; } - throwInvalidTDS(); } } @@ -6416,46 +6517,62 @@ private void sendFedAuthToken(FedAuthTokenCommand fedAuthCommand, SqlAuthenticat * Authentication Info. */ void onFedAuthInfo(SqlFedAuthInfo fedAuthInfo, TDSTokenHandler tdsTokenHandler) throws SQLServerException { - assert (null != activeConnectionProperties.getProperty(SQLServerDriverStringProperty.USER.toString()) - && null != activeConnectionProperties.getProperty(SQLServerDriverStringProperty.PASSWORD.toString())) - || (authenticationString.equalsIgnoreCase(SqlAuthentication.ACTIVE_DIRECTORY_INTEGRATED.toString()) - || authenticationString - .equalsIgnoreCase(SqlAuthentication.ACTIVE_DIRECTORY_MANAGED_IDENTITY.toString()) - || authenticationString - .equalsIgnoreCase(SqlAuthentication.ACTIVE_DIRECTORY_INTERACTIVE.toString()) - && fedAuthRequiredPreLoginResponse); - assert null != fedAuthInfo; + try (PerformanceLog.Scope fedAuthScope = PerformanceLog.createScope(PerformanceLog.perfLoggerConnection, + traceID, PerformanceActivity.TOKEN_ACQUISITION)) { + try { + assert (null != activeConnectionProperties.getProperty(SQLServerDriverStringProperty.USER.toString()) + && null != activeConnectionProperties + .getProperty(SQLServerDriverStringProperty.PASSWORD.toString())) + || (authenticationString + .equalsIgnoreCase(SqlAuthentication.ACTIVE_DIRECTORY_INTEGRATED.toString()) + || authenticationString + .equalsIgnoreCase( + SqlAuthentication.ACTIVE_DIRECTORY_MANAGED_IDENTITY.toString()) + || authenticationString + .equalsIgnoreCase(SqlAuthentication.ACTIVE_DIRECTORY_INTERACTIVE.toString()) + && fedAuthRequiredPreLoginResponse); + + assert null != fedAuthInfo; + + attemptRefreshTokenLocked = true; + + if (authenticationString.equals(SqlAuthentication.NOT_SPECIFIED.toString()) + && null != accessTokenCallbackClass + && !accessTokenCallbackClass.isEmpty()) { + try { + Object[] msgArgs = { "accessTokenCallbackClass", + "com.microsoft.sqlserver.jdbc.SQLServerAccessTokenCallback" }; + SQLServerAccessTokenCallback callbackInstance = Util.newInstance( + SQLServerAccessTokenCallback.class, + accessTokenCallbackClass, null, msgArgs); + fedAuthToken = callbackInstance.getAccessToken(fedAuthInfo.spn, fedAuthInfo.stsurl); + } catch (Exception e) { + MessageFormat form = new MessageFormat( + SQLServerException.getErrString("R_InvalidAccessTokenCallbackClass")); + throw new SQLServerException(form.format(new Object[] { accessTokenCallbackClass }), + e.getCause()); + } + } else if (authenticationString.equals(SqlAuthentication.NOT_SPECIFIED.toString()) + && null != accessTokenCallback) { + fedAuthToken = accessTokenCallback.getAccessToken(fedAuthInfo.spn, fedAuthInfo.stsurl); + } else { + fedAuthToken = getFedAuthToken(fedAuthInfo); + } - attemptRefreshTokenLocked = true; + attemptRefreshTokenLocked = false; + + // fedAuthToken cannot be null. + assert null != fedAuthToken; + + TDSCommand fedAuthCommand = new FedAuthTokenCommand(fedAuthToken, tdsTokenHandler); + fedAuthCommand.execute(tdsChannel.getWriter(), tdsChannel.getReader(fedAuthCommand)); - if (authenticationString.equals(SqlAuthentication.NOT_SPECIFIED.toString()) && null != accessTokenCallbackClass - && !accessTokenCallbackClass.isEmpty()) { - try { - Object[] msgArgs = {"accessTokenCallbackClass", - "com.microsoft.sqlserver.jdbc.SQLServerAccessTokenCallback"}; - SQLServerAccessTokenCallback callbackInstance = Util.newInstance(SQLServerAccessTokenCallback.class, - accessTokenCallbackClass, null, msgArgs); - fedAuthToken = callbackInstance.getAccessToken(fedAuthInfo.spn, fedAuthInfo.stsurl); } catch (Exception e) { - MessageFormat form = new MessageFormat( - SQLServerException.getErrString("R_InvalidAccessTokenCallbackClass")); - throw new SQLServerException(form.format(new Object[] {accessTokenCallbackClass}), e.getCause()); + fedAuthScope.setException(e); + throw e; } - } else if (authenticationString.equals(SqlAuthentication.NOT_SPECIFIED.toString()) - && null != accessTokenCallback) { - fedAuthToken = accessTokenCallback.getAccessToken(fedAuthInfo.spn, fedAuthInfo.stsurl); - } else { - fedAuthToken = getFedAuthToken(fedAuthInfo); } - - attemptRefreshTokenLocked = false; - - // fedAuthToken cannot be null. - assert null != fedAuthToken; - - TDSCommand fedAuthCommand = new FedAuthTokenCommand(fedAuthToken, tdsTokenHandler); - fedAuthCommand.execute(tdsChannel.getWriter(), tdsChannel.getReader(fedAuthCommand)); } private SqlAuthenticationToken getFedAuthToken(SqlFedAuthInfo fedAuthInfo) throws SQLServerException { @@ -6468,9 +6585,10 @@ private SqlAuthenticationToken getFedAuthToken(SqlFedAuthInfo fedAuthInfo) throw int fedauthSleepInterval = BACKOFF_INTERVAL; if (!msalContextExists() - && !authenticationString.equalsIgnoreCase(SqlAuthentication.ACTIVE_DIRECTORY_INTEGRATED.toString())) { + && !authenticationString + .equalsIgnoreCase(SqlAuthentication.ACTIVE_DIRECTORY_INTEGRATED.toString())) { MessageFormat form = new MessageFormat(SQLServerException.getErrString("R_MSALMissing")); - throw new SQLServerException(form.format(new Object[] {authenticationString}), null, 0, null); + throw new SQLServerException(form.format(new Object[] { authenticationString }), null, 0, null); } if (loggerExternal.isLoggable(java.util.logging.Level.FINEST)) { @@ -6481,7 +6599,8 @@ private SqlAuthenticationToken getFedAuthToken(SqlFedAuthInfo fedAuthInfo) throw int millisecondsRemaining = timerRemaining(timerExpire); if (authenticationString.equalsIgnoreCase(SqlAuthentication.ACTIVE_DIRECTORY_PASSWORD.toString())) { fedAuthToken = SQLServerMSAL4JUtils.getSqlFedAuthToken(fedAuthInfo, user, - activeConnectionProperties.getProperty(SQLServerDriverStringProperty.PASSWORD.toString()), + activeConnectionProperties + .getProperty(SQLServerDriverStringProperty.PASSWORD.toString()), authenticationString, millisecondsRemaining); // Break out of the retry loop in successful case. @@ -6499,7 +6618,8 @@ private SqlAuthenticationToken getFedAuthToken(SqlFedAuthInfo fedAuthInfo) throw } fedAuthToken = SQLServerSecurityUtility.getManagedIdentityCredAuthToken(fedAuthInfo.spn, - activeConnectionProperties.getProperty(SQLServerDriverStringProperty.MSI_CLIENT_ID.toString()), + activeConnectionProperties + .getProperty(SQLServerDriverStringProperty.MSI_CLIENT_ID.toString()), millisecondsRemaining); // Break out of the retry loop in successful case. @@ -6507,36 +6627,43 @@ private SqlAuthenticationToken getFedAuthToken(SqlFedAuthInfo fedAuthInfo) throw } else if (authenticationString .equalsIgnoreCase(SqlAuthentication.ACTIVE_DIRECTORY_SERVICE_PRINCIPAL.toString())) { - // aadPrincipalID and aadPrincipalSecret is deprecated replaced by username and password + // aadPrincipalID and aadPrincipalSecret is deprecated replaced by username and + // password if (aadPrincipalID != null && !aadPrincipalID.isEmpty() && aadPrincipalSecret != null && !aadPrincipalSecret.isEmpty()) { fedAuthToken = SQLServerMSAL4JUtils.getSqlFedAuthTokenPrincipal(fedAuthInfo, aadPrincipalID, aadPrincipalSecret, authenticationString, millisecondsRemaining); } else { fedAuthToken = SQLServerMSAL4JUtils.getSqlFedAuthTokenPrincipal(fedAuthInfo, - activeConnectionProperties.getProperty(SQLServerDriverStringProperty.USER.toString()), - activeConnectionProperties.getProperty(SQLServerDriverStringProperty.PASSWORD.toString()), + activeConnectionProperties + .getProperty(SQLServerDriverStringProperty.USER.toString()), + activeConnectionProperties + .getProperty(SQLServerDriverStringProperty.PASSWORD.toString()), authenticationString, millisecondsRemaining); } // Break out of the retry loop in successful case. break; } else if (authenticationString - .equalsIgnoreCase(SqlAuthentication.ACTIVE_DIRECTORY_SERVICE_PRINCIPAL_CERTIFICATE.toString())) { + .equalsIgnoreCase( + SqlAuthentication.ACTIVE_DIRECTORY_SERVICE_PRINCIPAL_CERTIFICATE.toString())) { // clientCertificate property is used to specify path to certificate file fedAuthToken = SQLServerMSAL4JUtils.getSqlFedAuthTokenPrincipalCertificate(fedAuthInfo, activeConnectionProperties.getProperty(SQLServerDriverStringProperty.USER.toString()), servicePrincipalCertificate, - activeConnectionProperties.getProperty(SQLServerDriverStringProperty.PASSWORD.toString()), - servicePrincipalCertificateKey, servicePrincipalCertificatePassword, authenticationString, + activeConnectionProperties + .getProperty(SQLServerDriverStringProperty.PASSWORD.toString()), + servicePrincipalCertificateKey, servicePrincipalCertificatePassword, + authenticationString, millisecondsRemaining); // Break out of the retry loop in successful case. break; } else if (authenticationString .equalsIgnoreCase(SqlAuthentication.ACTIVE_DIRECTORY_INTEGRATED.toString())) { - // If operating system is windows and mssql-jdbc_auth is loaded then choose the DLL authentication. + // If operating system is windows and mssql-jdbc_auth is loaded then choose the + // DLL authentication. if (isWindows && AuthenticationJNI.isDllLoaded()) { try { FedAuthDllInfo dllInfo = AuthenticationJNI.getAccessTokenForWindowsIntegrated( @@ -6556,44 +6683,48 @@ private SqlAuthenticationToken getFedAuthToken(SqlFedAuthInfo fedAuthInfo) throw break; } catch (DLLException adalException) { - // the mssql-jdbc_auth DLL return -1 for errorCategory, if unable to load the adalsql DLL + // the mssql-jdbc_auth DLL return -1 for errorCategory, if unable to load the + // adalsql DLL int errorCategory = adalException.getCategory(); if (-1 == errorCategory) { MessageFormat form = new MessageFormat( SQLServerException.getErrString("R_UnableLoadADALSqlDll")); - Object[] msgArgs = {Integer.toHexString(adalException.getState())}; + Object[] msgArgs = { Integer.toHexString(adalException.getState()) }; throw new SQLServerException(form.format(msgArgs), null); } millisecondsRemaining = timerRemaining(timerExpire); if (ActiveDirectoryAuthentication.GET_ACCESS_TOKEN_TRANSIENT_ERROR != errorCategory - || timerHasExpired(timerExpire) || (fedauthSleepInterval >= millisecondsRemaining)) { + || timerHasExpired(timerExpire) + || (fedauthSleepInterval >= millisecondsRemaining)) { String errorStatus = Integer.toHexString(adalException.getStatus()); if (connectionlogger.isLoggable(Level.FINER)) { connectionlogger.fine( - toString() + " SQLServerConnection.getFedAuthToken.AdalException category:" + toString() + + " SQLServerConnection.getFedAuthToken.AdalException category:" + errorCategory + " error: " + errorStatus); } MessageFormat form = new MessageFormat( SQLServerException.getErrString("R_ADALAuthenticationMiddleErrorMessage")); String errorCode = Integer.toHexString(adalException.getStatus()).toUpperCase(); - Object[] msgArgs1 = {errorCode, adalException.getState()}; + Object[] msgArgs1 = { errorCode, adalException.getState() }; SQLServerException middleException = new SQLServerException(form.format(msgArgs1), adalException); form = new MessageFormat(SQLServerException.getErrString("R_MSALExecution")); - Object[] msgArgs = {user, authenticationString}; + Object[] msgArgs = { user, authenticationString }; throw new SQLServerException(form.format(msgArgs), null, 0, middleException); } if (connectionlogger.isLoggable(Level.FINER)) { connectionlogger.fine(toString() + " SQLServerConnection.getFedAuthToken sleeping: " + fedauthSleepInterval + " milliseconds."); - connectionlogger.fine(toString() + " SQLServerConnection.getFedAuthToken remaining: " - + millisecondsRemaining + " milliseconds."); + connectionlogger + .fine(toString() + " SQLServerConnection.getFedAuthToken remaining: " + + millisecondsRemaining + " milliseconds."); } sleepForInterval(fedauthSleepInterval); @@ -6601,17 +6732,20 @@ private SqlAuthenticationToken getFedAuthToken(SqlFedAuthInfo fedAuthInfo) throw } } - // else choose MSAL4J for integrated authentication. This option is supported for both windows and unix, + // else choose MSAL4J for integrated authentication. This option is supported + // for both windows and unix, // so we don't need to check the // OS version here. else { // Check if MSAL4J library is available if (!msalContextExists()) { - MessageFormat form = new MessageFormat(SQLServerException.getErrString("R_DLLandMSALMissing")); - Object[] msgArgs = {SQLServerDriver.AUTH_DLL_NAME, authenticationString}; + MessageFormat form = new MessageFormat( + SQLServerException.getErrString("R_DLLandMSALMissing")); + Object[] msgArgs = { SQLServerDriver.AUTH_DLL_NAME, authenticationString }; throw new SQLServerException(form.format(msgArgs), null, 0, null); } - fedAuthToken = SQLServerMSAL4JUtils.getSqlFedAuthTokenIntegrated(fedAuthInfo, authenticationString, + fedAuthToken = SQLServerMSAL4JUtils.getSqlFedAuthTokenIntegrated(fedAuthInfo, + authenticationString, millisecondsRemaining); } // Break out of the retry loop in successful case. @@ -6624,7 +6758,8 @@ private SqlAuthenticationToken getFedAuthToken(SqlFedAuthInfo fedAuthInfo) throw // Break out of the retry loop in successful case. break; - } else if (authenticationString.equalsIgnoreCase(SqlAuthentication.ACTIVE_DIRECTORY_DEFAULT.toString())) { + } else if (authenticationString + .equalsIgnoreCase(SqlAuthentication.ACTIVE_DIRECTORY_DEFAULT.toString())) { String managedIdentityClientId = activeConnectionProperties .getProperty(SQLServerDriverStringProperty.USER.toString()); @@ -6635,7 +6770,8 @@ private SqlAuthenticationToken getFedAuthToken(SqlFedAuthInfo fedAuthInfo) throw } fedAuthToken = SQLServerSecurityUtility.getDefaultAzureCredAuthToken(fedAuthInfo.spn, - activeConnectionProperties.getProperty(SQLServerDriverStringProperty.MSI_CLIENT_ID.toString()), + activeConnectionProperties + .getProperty(SQLServerDriverStringProperty.MSI_CLIENT_ID.toString()), millisecondsRemaining); break; @@ -6643,6 +6779,7 @@ private SqlAuthenticationToken getFedAuthToken(SqlFedAuthInfo fedAuthInfo) throw } return fedAuthToken; + } private boolean msalContextExists() { diff --git a/src/test/java/com/microsoft/sqlserver/jdbc/PerformanceLogCallbackTest.java b/src/test/java/com/microsoft/sqlserver/jdbc/PerformanceLogCallbackTest.java new file mode 100644 index 000000000..acfdec1fb --- /dev/null +++ b/src/test/java/com/microsoft/sqlserver/jdbc/PerformanceLogCallbackTest.java @@ -0,0 +1,85 @@ +/* + * Microsoft JDBC Driver for SQL Server Copyright(c) 2016 Microsoft Corporation All rights reserved. This program is + * made available under the terms of the MIT License. See the LICENSE file in the project root for more information. + */ + +package com.microsoft.sqlserver.jdbc; + +import org.junit.jupiter.api.AfterEach; +import org.junit.jupiter.api.Test; + +import com.microsoft.sqlserver.testframework.AbstractTest; + +import java.io.IOException; +import java.nio.file.Files; +import java.nio.file.Path; +import java.nio.file.Paths; +import java.sql.Connection; +import java.sql.DatabaseMetaData; +import java.util.concurrent.atomic.AtomicBoolean; +import java.util.logging.FileHandler; +import java.util.logging.Level; +import java.util.logging.Logger; +import java.util.logging.SimpleFormatter; + +import static org.junit.jupiter.api.Assertions.assertTrue; + +class PerformanceLogCallbackTest extends AbstractTest { + + private static final Logger perfLogger = Logger.getLogger("com.microsoft.sqlserver.jdbc.PerformanceMetrics.Connection"); + private static final Path logPath = Paths.get("performance.log"); + private static FileHandler perfLogHandler; + + static { + try { + perfLogHandler = new FileHandler("performance.log", true); + perfLogHandler.setFormatter(new SimpleFormatter()); + perfLogger.addHandler(perfLogHandler); + perfLogger.setLevel(Level.INFO); + perfLogger.setUseParentHandlers(false); + } catch (IOException e) { + e.printStackTrace(); + } + } + + @AfterEach + void cleanUpAfter() throws IOException { + // Remove and close handler before deleting file + if (perfLogHandler != null) { + perfLogger.removeHandler(perfLogHandler); + perfLogHandler.close(); + } + Files.deleteIfExists(logPath); + } + + /** + * Test to validate the PerformanceLogCallback is called and the log file is created. + */ + @Test + void testPublishIsCalledAndLogFileCreated() throws Exception { + AtomicBoolean called = new AtomicBoolean(false); + + PerformanceLogCallback callbackInstance = new PerformanceLogCallback() { + @Override + public void publish(long durationMs, PerformanceActivity activity, Exception exception) { + called.set(true); + } + }; + + PerformanceLog.registerCallback(callbackInstance); + + try (Connection con = getConnection()) { + DatabaseMetaData metaData = con.getMetaData(); + System.out.println("Database Product Name: " + metaData.getDatabaseProductName()); + System.out.println("Database Product Version: " + metaData.getDatabaseProductVersion()); + } + + assertTrue(called.get(), "PerformanceLogCallback.publish should have been called"); + assertTrue(callbackInstance instanceof PerformanceLogCallback, "Callback must implement PerformanceLogCallback"); + assertTrue(Files.exists(logPath), "performance.log file should exist"); + System.out.println("Log file absolute path: " + logPath.toAbsolutePath()); + + PerformanceLog.unregisterCallback(); + + } +} \ No newline at end of file