You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@mina.apache.org by lg...@apache.org on 2019/12/05 17:44:32 UTC
[mina-sshd] 02/09: [SSHD-956] Using System#nanoTime to measure
session idle/authentication timeouts
This is an automated email from the ASF dual-hosted git repository.
lgoldstein pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/mina-sshd.git
commit 9a0d8a960e6181982128146f651cc7bb3065bc1e
Author: Lyor Goldstein <lg...@apache.org>
AuthorDate: Thu Nov 28 20:21:22 2019 +0200
[SSHD-956] Using System#nanoTime to measure session idle/authentication timeouts
---
CHANGES.md | 2 +
.../sshd/common/session/helpers/SessionHelper.java | 39 ++++++++++-----
.../client/simple/SimpleSessionClientTest.java | 18 ++++---
.../java/org/apache/sshd/server/ServerTest.java | 58 +++++++++++++++-------
4 files changed, 79 insertions(+), 38 deletions(-)
diff --git a/CHANGES.md b/CHANGES.md
index f656e5d..2d4c669 100644
--- a/CHANGES.md
+++ b/CHANGES.md
@@ -104,3 +104,5 @@ for the server's identification before sending KEX-INIT message.
* [SSHD-953](https://issues.apache.org/jira/browse/SSHD-953) - Parse and strip quoted command arguments when executing a server-side command via local shell.
* [SSHD-955](https://issues.apache.org/jira/browse/SSHD-955) - Provide configurable control over auto-detected password prompt in client-side `UserAuthKeyboardInteractive` implementation.
+
+* [SSHD-956](https://issues.apache.org/jira/browse/SSHD-956) - Using `System#nanoTime` to measure session idle/authentication timeouts
diff --git a/sshd-core/src/main/java/org/apache/sshd/common/session/helpers/SessionHelper.java b/sshd-core/src/main/java/org/apache/sshd/common/session/helpers/SessionHelper.java
index baf056d..6003372 100644
--- a/sshd-core/src/main/java/org/apache/sshd/common/session/helpers/SessionHelper.java
+++ b/sshd-core/src/main/java/org/apache/sshd/common/session/helpers/SessionHelper.java
@@ -80,6 +80,10 @@ public abstract class SessionHelper extends AbstractKexFactoryManager implements
/** Session level lock for regulating access to sensitive data */
protected final Object sessionLock = new Object();
+ // Session timeout measurements
+ protected long authNanoStart = System.nanoTime();
+ protected long idleNanoStart = System.nanoTime();
+
/** Client or server side */
private final boolean serverSession;
@@ -213,13 +217,13 @@ public abstract class SessionHelper extends AbstractKexFactoryManager implements
}
/**
- * Checks whether the session has timed out (both auth and idle timeouts are checked).
+ * Checks whether the session has timed out (both authentication and idle timeouts are checked).
* If the session has timed out, a DISCONNECT message will be sent.
*
* @return An indication whether timeout has been detected
* @throws IOException If failed to check
- * @see #checkAuthenticationTimeout(long, long)
- * @see #checkIdleTimeout(long, long)
+ * @see #checkAuthenticationTimeout(long, long, long)
+ * @see #checkIdleTimeout(long, long, long)
*/
protected TimeoutIndicator checkForTimeouts() throws IOException {
if ((!isOpen()) || isClosing() || isClosed()) {
@@ -241,9 +245,10 @@ public abstract class SessionHelper extends AbstractKexFactoryManager implements
}
long now = System.currentTimeMillis();
- result = checkAuthenticationTimeout(now, getAuthTimeout());
+ long nanoTime = System.nanoTime();
+ result = checkAuthenticationTimeout(now, nanoTime, getAuthTimeout());
if (result == null) {
- result = checkIdleTimeout(now, getIdleTimeout());
+ result = checkIdleTimeout(now, nanoTime, getIdleTimeout());
}
status = (result == null) ? TimeoutStatus.NoTimeout : result.getStatus();
@@ -304,6 +309,7 @@ public abstract class SessionHelper extends AbstractKexFactoryManager implements
public long resetAuthTimeout() {
long value = getAuthTimeoutStart();
this.authTimeoutStart = System.currentTimeMillis();
+ this.authNanoStart = System.nanoTime();
return value;
}
@@ -311,15 +317,18 @@ public abstract class SessionHelper extends AbstractKexFactoryManager implements
* Checks if authentication timeout expired
*
* @param now The current time in millis
+ * @param nanoTime {@link System#nanoTime()} value
* @param authTimeoutMs The configured timeout in millis - if non-positive then no timeout
* @return A {@link TimeoutIndicator} specifying the timeout status and disconnect reason
* message if timeout expired, {@code null} or {@code NoTimeout} if no timeout occurred
* @see #getAuthTimeout()
*/
- protected TimeoutIndicator checkAuthenticationTimeout(long now, long authTimeoutMs) {
- long authDiff = now - getAuthTimeoutStart();
- if ((!isAuthenticated()) && (authTimeoutMs > 0L) && (authDiff > authTimeoutMs)) {
- return new TimeoutIndicator(TimeoutStatus.AuthTimeout, authTimeoutMs, authDiff);
+ protected TimeoutIndicator checkAuthenticationTimeout(
+ long now, long nanoTime, long authTimeoutMs) {
+ long authDiffNano = nanoTime - authNanoStart;
+ long authDiffMs = TimeUnit.NANOSECONDS.toMillis(authDiffNano);
+ if ((!isAuthenticated()) && (authTimeoutMs > 0L) && (authDiffMs > authTimeoutMs)) {
+ return new TimeoutIndicator(TimeoutStatus.AuthTimeout, authTimeoutMs, authDiffMs);
} else {
return null;
}
@@ -334,15 +343,18 @@ public abstract class SessionHelper extends AbstractKexFactoryManager implements
* Checks if idle timeout expired
*
* @param now The current time in millis
+ * @param nanoTime {@link System#nanoTime()} value
* @param idleTimeoutMs The configured timeout in millis - if non-positive then no timeout
* @return A {@link TimeoutIndicator} specifying the timeout status and disconnect reason
* message if timeout expired, {@code null} or {@code NoTimeout} if no timeout occurred
* @see #getIdleTimeout()
*/
- protected TimeoutIndicator checkIdleTimeout(long now, long idleTimeoutMs) {
- long idleDiff = now - getIdleTimeoutStart();
- if ((idleTimeoutMs > 0L) && (idleDiff > idleTimeoutMs)) {
- return new TimeoutIndicator(TimeoutStatus.IdleTimeout, idleTimeoutMs, idleDiff);
+ protected TimeoutIndicator checkIdleTimeout(
+ long now, long nanoTime, long idleTimeoutMs) {
+ long idleDiffNano = nanoTime - idleNanoStart;
+ long idleDiffMs = TimeUnit.NANOSECONDS.toMillis(idleDiffNano);
+ if ((idleTimeoutMs > 0L) && (idleDiffMs > idleTimeoutMs)) {
+ return new TimeoutIndicator(TimeoutStatus.IdleTimeout, idleTimeoutMs, idleDiffMs);
} else {
return null;
}
@@ -352,6 +364,7 @@ public abstract class SessionHelper extends AbstractKexFactoryManager implements
public long resetIdleTimeout() {
long value = getIdleTimeoutStart();
this.idleTimeoutStart = System.currentTimeMillis();
+ this.idleNanoStart = System.nanoTime();
return value;
}
diff --git a/sshd-core/src/test/java/org/apache/sshd/client/simple/SimpleSessionClientTest.java b/sshd-core/src/test/java/org/apache/sshd/client/simple/SimpleSessionClientTest.java
index a095f81..fb12ffd 100644
--- a/sshd-core/src/test/java/org/apache/sshd/client/simple/SimpleSessionClientTest.java
+++ b/sshd-core/src/test/java/org/apache/sshd/client/simple/SimpleSessionClientTest.java
@@ -53,7 +53,8 @@ public class SimpleSessionClientTest extends BaseSimpleClientTestSupport {
sshd.setPublickeyAuthenticator(RejectAllPublickeyAuthenticator.INSTANCE);
client.start();
- try (ClientSession session = simple.sessionLogin(TEST_LOCALHOST, port, getCurrentTestName(), getCurrentTestName())) {
+ try (ClientSession session = simple.sessionLogin(
+ TEST_LOCALHOST, port, getCurrentTestName(), getCurrentTestName())) {
assertEquals("Mismatched session username", getCurrentTestName(), session.getUsername());
}
}
@@ -74,8 +75,10 @@ public class SimpleSessionClientTest extends BaseSimpleClientTestSupport {
sshd.setPasswordAuthenticator(RejectAllPasswordAuthenticator.INSTANCE);
client.start();
- try (ClientSession session = simple.sessionLogin(TEST_LOCALHOST, port, getCurrentTestName(), identity)) {
- assertEquals("Mismatched session username", getCurrentTestName(), session.getUsername());
+ try (ClientSession session = simple.sessionLogin(
+ TEST_LOCALHOST, port, getCurrentTestName(), identity)) {
+ assertEquals("Mismatched session username",
+ getCurrentTestName(), session.getUsername());
assertTrue("User identity not queried", identityQueried.get());
}
}
@@ -95,7 +98,8 @@ public class SimpleSessionClientTest extends BaseSimpleClientTestSupport {
client.start();
long nanoStart = System.nanoTime();
- try (ClientSession session = simple.sessionLogin(TEST_LOCALHOST, port, getCurrentTestName(), getCurrentTestName())) {
+ try (ClientSession session = simple.sessionLogin(
+ TEST_LOCALHOST, port, getCurrentTestName(), getCurrentTestName())) {
fail("Unexpected connection success");
} catch (IOException e) {
long nanoEnd = System.nanoTime();
@@ -110,7 +114,8 @@ public class SimpleSessionClientTest extends BaseSimpleClientTestSupport {
public void testAuthenticationTimeout() throws Exception {
// make sure authentication occurs only for passwords
sshd.setPublickeyAuthenticator(RejectAllPublickeyAuthenticator.INSTANCE);
- PasswordAuthenticator delegate = Objects.requireNonNull(sshd.getPasswordAuthenticator(), "No password authenticator");
+ PasswordAuthenticator delegate = Objects.requireNonNull(
+ sshd.getPasswordAuthenticator(), "No password authenticator");
sshd.setPasswordAuthenticator((username, password, session) -> {
try {
Thread.sleep(AUTH_TIMEOUT + 150L);
@@ -122,7 +127,8 @@ public class SimpleSessionClientTest extends BaseSimpleClientTestSupport {
client.start();
long nanoStart = System.nanoTime();
- try (ClientSession session = simple.sessionLogin(TEST_LOCALHOST, port, getCurrentTestName(), getCurrentTestName())) {
+ try (ClientSession session = simple.sessionLogin(
+ TEST_LOCALHOST, port, getCurrentTestName(), getCurrentTestName())) {
fail("Unexpected connection success");
} catch (IOException e) {
long nanoEnd = System.nanoTime();
diff --git a/sshd-core/src/test/java/org/apache/sshd/server/ServerTest.java b/sshd-core/src/test/java/org/apache/sshd/server/ServerTest.java
index 62f4371..2666b73 100644
--- a/sshd-core/src/test/java/org/apache/sshd/server/ServerTest.java
+++ b/sshd-core/src/test/java/org/apache/sshd/server/ServerTest.java
@@ -89,6 +89,7 @@ import org.junit.Before;
import org.junit.FixMethodOrder;
import org.junit.Test;
import org.junit.runners.MethodSorters;
+import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
/**
@@ -206,13 +207,15 @@ public class ServerTest extends BaseTestSupport {
AtomicReference<TimeoutIndicator> timeoutHolder = new AtomicReference<>(TimeoutIndicator.NONE);
sshd.setSessionDisconnectHandler(new SessionDisconnectHandler() {
@Override
- public boolean handleTimeoutDisconnectReason(Session session, TimeoutIndicator timeoutStatus)
- throws IOException {
+ public boolean handleTimeoutDisconnectReason(
+ Session session, TimeoutIndicator timeoutStatus)
+ throws IOException {
outputDebugMessage("Session %s timeout reported: %s", session, timeoutStatus);
TimeoutIndicator prev = timeoutHolder.getAndSet(timeoutStatus);
if (prev != TimeoutIndicator.NONE) {
- throw new StreamCorruptedException("Multiple timeout disconnects: " + timeoutStatus + " / " + prev);
+ throw new StreamCorruptedException(
+ "Multiple timeout disconnects: " + timeoutStatus + " / " + prev);
}
return false;
}
@@ -238,7 +241,8 @@ public class ServerTest extends BaseTestSupport {
}
TimeoutIndicator status = timeoutHolder.getAndSet(null);
- assertSame("Mismatched timeout status reported", TimeoutIndicator.TimeoutStatus.AuthTimeout, status.getStatus());
+ assertSame("Mismatched timeout status reported",
+ TimeoutIndicator.TimeoutStatus.AuthTimeout, status.getStatus());
}
@Test
@@ -250,12 +254,14 @@ public class ServerTest extends BaseTestSupport {
TestEchoShell.latch = new CountDownLatch(1);
sshd.setSessionDisconnectHandler(new SessionDisconnectHandler() {
@Override
- public boolean handleTimeoutDisconnectReason(Session session, TimeoutIndicator timeoutStatus)
- throws IOException {
+ public boolean handleTimeoutDisconnectReason(
+ Session session, TimeoutIndicator timeoutStatus)
+ throws IOException {
outputDebugMessage("Session %s timeout reported: %s", session, timeoutStatus);
TimeoutIndicator prev = timeoutHolder.getAndSet(timeoutStatus);
if (prev != TimeoutIndicator.NONE) {
- throw new StreamCorruptedException("Multiple timeout disconnects: " + timeoutStatus + " / " + prev);
+ throw new StreamCorruptedException(
+ "Multiple timeout disconnects: " + timeoutStatus + " / " + prev);
}
return false;
}
@@ -314,15 +320,20 @@ public class ServerTest extends BaseTestSupport {
shell.setErr(err);
shell.open().verify(9L, TimeUnit.SECONDS);
- assertTrue("No changes in activated channels", channelListener.waitForActiveChannelsChange(5L, TimeUnit.SECONDS));
- assertTrue("No changes in open channels", channelListener.waitForOpenChannelsChange(5L, TimeUnit.SECONDS));
+ assertTrue("No changes in activated channels",
+ channelListener.waitForActiveChannelsChange(5L, TimeUnit.SECONDS));
+ assertTrue("No changes in open channels",
+ channelListener.waitForOpenChannelsChange(5L, TimeUnit.SECONDS));
long waitStart = System.currentTimeMillis();
Collection<ClientSession.ClientSessionEvent> res =
s.waitFor(EnumSet.of(ClientSession.ClientSessionEvent.CLOSED), 3L * testIdleTimeout);
long waitEnd = System.currentTimeMillis();
assertTrue("Invalid session state after " + (waitEnd - waitStart) + " ms: " + res,
- res.containsAll(EnumSet.of(ClientSession.ClientSessionEvent.CLOSED, ClientSession.ClientSessionEvent.AUTHED)));
+ res.containsAll(
+ EnumSet.of(
+ ClientSession.ClientSessionEvent.CLOSED,
+ ClientSession.ClientSessionEvent.AUTHED)));
} finally {
client.stop();
}
@@ -344,10 +355,12 @@ public class ServerTest extends BaseTestSupport {
@Test
public void testServerIdleTimeoutWithForce() throws Exception {
final long idleTimeoutValue = TimeUnit.SECONDS.toMillis(5L);
- PropertyResolverUtils.updateProperty(sshd, FactoryManager.IDLE_TIMEOUT, idleTimeoutValue);
+ PropertyResolverUtils.updateProperty(
+ sshd, FactoryManager.IDLE_TIMEOUT, idleTimeoutValue);
final long disconnectTimeoutValue = TimeUnit.SECONDS.toMillis(2L);
- PropertyResolverUtils.updateProperty(sshd, FactoryManager.DISCONNECT_TIMEOUT, disconnectTimeoutValue);
+ PropertyResolverUtils.updateProperty(
+ sshd, FactoryManager.DISCONNECT_TIMEOUT, disconnectTimeoutValue);
CountDownLatch latch = new CountDownLatch(1);
sshd.setCommandFactory((channel, command) -> new StreamCommand(command));
@@ -364,7 +377,8 @@ public class ServerTest extends BaseTestSupport {
@Override
public void sessionException(Session session, Throwable t) {
- outputDebugMessage("Session %s exception %s caught: %s", session, t.getClass().getSimpleName(), t.getMessage());
+ outputDebugMessage("Session %s exception %s caught: %s",
+ session, t.getClass().getSimpleName(), t.getMessage());
}
@Override
@@ -393,16 +407,21 @@ public class ServerTest extends BaseTestSupport {
shell.setOut(pos);
shell.open().verify(5L, TimeUnit.SECONDS);
- assertTrue("No changes in activated channels", channelListener.waitForActiveChannelsChange(5L, TimeUnit.SECONDS));
- assertTrue("No changes in open channels", channelListener.waitForOpenChannelsChange(5L, TimeUnit.SECONDS));
+ assertTrue("No changes in activated channels",
+ channelListener.waitForActiveChannelsChange(5L, TimeUnit.SECONDS));
+ assertTrue("No changes in open channels",
+ channelListener.waitForOpenChannelsChange(5L, TimeUnit.SECONDS));
try (AbstractSession serverSession = GenericUtils.head(sshd.getActiveSessions())) {
- AbstractConnectionService service = serverSession.getService(AbstractConnectionService.class);
+ AbstractConnectionService service =
+ serverSession.getService(AbstractConnectionService.class);
Collection<? extends Channel> channels = service.getChannels();
try (Channel channel = GenericUtils.head(channels)) {
- final long maxTimeoutValue = idleTimeoutValue + disconnectTimeoutValue + TimeUnit.SECONDS.toMillis(3L);
- final long maxWaitNanos = TimeUnit.MILLISECONDS.toNanos(maxTimeoutValue);
+ final long maxTimeoutValue =
+ idleTimeoutValue + disconnectTimeoutValue + TimeUnit.SECONDS.toMillis(3L);
+ final long maxWaitNanos =
+ TimeUnit.MILLISECONDS.toNanos(maxTimeoutValue);
Window wRemote = channel.getRemoteWindow();
for (long totalNanoTime = 0L; wRemote.getSize() > 0;) {
long nanoStart = System.nanoTime();
@@ -414,7 +433,8 @@ public class ServerTest extends BaseTestSupport {
assertTrue("Waiting for too long on remote window size to reach zero", totalNanoTime < maxWaitNanos);
}
- LoggerFactory.getLogger(getClass()).info("Waiting for session idle timeouts");
+ Logger logger = LoggerFactory.getLogger(getClass());
+ logger.info("Waiting for session idle timeouts");
long t0 = System.currentTimeMillis();
latch.await(1L, TimeUnit.MINUTES);