From f55e4a5d3ec84960e7d095d75b7051811d20a843 Mon Sep 17 00:00:00 2001 From: Alex Heneveld Date: Wed, 30 Nov 2011 16:01:27 +0000 Subject: [PATCH 1/5] merged duplicate code branches --- .../src/main/java/org/jclouds/sshj/SshjSshClient.java | 9 ++------- 1 file changed, 2 insertions(+), 7 deletions(-) diff --git a/drivers/sshj/src/main/java/org/jclouds/sshj/SshjSshClient.java b/drivers/sshj/src/main/java/org/jclouds/sshj/SshjSshClient.java index c8d642f6ef..e8de1fa523 100644 --- a/drivers/sshj/src/main/java/org/jclouds/sshj/SshjSshClient.java +++ b/drivers/sshj/src/main/java/org/jclouds/sshj/SshjSshClient.java @@ -231,13 +231,8 @@ public class SshjSshClient implements SshClient { if (i + 1 == sshRetries) { logger.error(from, "<< " + errorMessage + ": out of retries %d", sshRetries); throw propagate(from, errorMessage); - } else if (Throwables2.getFirstThrowableOfType(from, IllegalStateException.class) != null) { - logger.warn(from, "<< " + errorMessage + ": " + from.getMessage()); - backoffForAttempt(i + 1, errorMessage + ": " + from.getMessage()); - if (connection != sshConnection) - connect(); - continue; - } else if (shouldRetry(from)) { + } else if (shouldRetry(from) || + (Throwables2.getFirstThrowableOfType(from, IllegalStateException.class) != null)) { logger.warn(from, "<< " + errorMessage + ": " + from.getMessage()); backoffForAttempt(i + 1, errorMessage + ": " + from.getMessage()); if (connection != sshConnection) From 4d11d4ef057dd4bdcc2c8de431a420f712c28cf7 Mon Sep 17 00:00:00 2001 From: Alex Heneveld Date: Wed, 30 Nov 2011 16:03:23 +0000 Subject: [PATCH 2/5] removed redundant error logging (was done by caller and also in propagate method; have removed from caller; might be better to remove from propagate, and leave at discretion of caller, because some places the "error" might be benign, and shouldn't log error at all, or not at >=WARN, but rather just leave at discretion of caller) --- .../sshj/src/main/java/org/jclouds/sshj/SshjSshClient.java | 6 ++---- 1 file changed, 2 insertions(+), 4 deletions(-) diff --git a/drivers/sshj/src/main/java/org/jclouds/sshj/SshjSshClient.java b/drivers/sshj/src/main/java/org/jclouds/sshj/SshjSshClient.java index e8de1fa523..e0ad403f36 100644 --- a/drivers/sshj/src/main/java/org/jclouds/sshj/SshjSshClient.java +++ b/drivers/sshj/src/main/java/org/jclouds/sshj/SshjSshClient.java @@ -229,8 +229,7 @@ public class SshjSshClient implements SshClient { logger.warn(from, "<< (%s) error closing connection", toString()); } if (i + 1 == sshRetries) { - logger.error(from, "<< " + errorMessage + ": out of retries %d", sshRetries); - throw propagate(from, errorMessage); + throw propagate(from, errorMessage+" (out of retries - max "+sshRetries+")"); } else if (shouldRetry(from) || (Throwables2.getFirstThrowableOfType(from, IllegalStateException.class) != null)) { logger.warn(from, "<< " + errorMessage + ": " + from.getMessage()); @@ -239,8 +238,7 @@ public class SshjSshClient implements SshClient { connect(); continue; } else { - logger.error(from, "<< " + errorMessage + ": exception not retryable"); - throw propagate(from, errorMessage); + throw propagate(from, errorMessage+" (not retryable)"); } } } From c8d614e360679f73080c04e1cd9bd83f2f61f252 Mon Sep 17 00:00:00 2001 From: Alex Heneveld Date: Wed, 30 Nov 2011 16:06:18 +0000 Subject: [PATCH 3/5] don't log warning if exception is retryable, downgraded to an info message --- drivers/sshj/src/main/java/org/jclouds/sshj/SshjSshClient.java | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/drivers/sshj/src/main/java/org/jclouds/sshj/SshjSshClient.java b/drivers/sshj/src/main/java/org/jclouds/sshj/SshjSshClient.java index e0ad403f36..97ded631c0 100644 --- a/drivers/sshj/src/main/java/org/jclouds/sshj/SshjSshClient.java +++ b/drivers/sshj/src/main/java/org/jclouds/sshj/SshjSshClient.java @@ -232,7 +232,7 @@ public class SshjSshClient implements SshClient { throw propagate(from, errorMessage+" (out of retries - max "+sshRetries+")"); } else if (shouldRetry(from) || (Throwables2.getFirstThrowableOfType(from, IllegalStateException.class) != null)) { - logger.warn(from, "<< " + errorMessage + ": " + from.getMessage()); + logger.info("<< " + errorMessage + " (attempt " + (i + 1) + " of " + sshRetries + "): " + from.getMessage()); backoffForAttempt(i + 1, errorMessage + ": " + from.getMessage()); if (connection != sshConnection) connect(); From 7b0353560d88bc2f537ec4a239b57cdc975fb145 Mon Sep 17 00:00:00 2001 From: Alex Heneveld Date: Wed, 30 Nov 2011 18:26:30 +0000 Subject: [PATCH 4/5] in-memory logger for use in tests, with tests --- .../org/jclouds/logging/BufferLogger.java | 154 ++++++++++++++++++ .../org/jclouds/logging/BufferLoggerTest.java | 31 ++++ 2 files changed, 185 insertions(+) create mode 100644 core/src/test/java/org/jclouds/logging/BufferLogger.java create mode 100644 core/src/test/java/org/jclouds/logging/BufferLoggerTest.java diff --git a/core/src/test/java/org/jclouds/logging/BufferLogger.java b/core/src/test/java/org/jclouds/logging/BufferLogger.java new file mode 100644 index 0000000000..9618c01353 --- /dev/null +++ b/core/src/test/java/org/jclouds/logging/BufferLogger.java @@ -0,0 +1,154 @@ +package org.jclouds.logging; + +import java.util.ArrayList; +import java.util.Collections; +import java.util.List; +import java.util.logging.Level; + +import junit.framework.AssertionFailedError; + +import org.jclouds.logging.BaseLogger; + +import com.google.common.base.Predicate; + +/** A logger implementation for use in testing; all log messages are remembered, \ + * but not written anywhere. The messages can then be inspected {@link #getMessages()} + * or certain assertions applied (see assertXxx methods on these instances) */ +public class BufferLogger extends BaseLogger { + + final String category; + Level level = Level.INFO; + List messages = Collections.synchronizedList(new ArrayList()); + + public static class Record { + Level level; + String message; + Throwable trace; + public Record(Level level, String message, Throwable trace) { + this.level = level; + this.message = message; + this.trace = trace; + } + public Level getLevel() { + return level; + } + public String getMessage() { + return message; + } + public Throwable getTrace() { + return trace; + } + } + + + public BufferLogger(String category) { + this.category = category; + } + + public List getMessages() { + return messages; + } + + /** throws AssertionFailedError if the log does not contain the indicated fragment; + * otherwise returns a record which does satisfy the constraint + */ + public Record assertLogContains(String fragment) { + for (Record r: messages) { + if (r.getMessage()!=null && r.getMessage().contains(fragment)) return r; + } + throw new AssertionFailedError("log did not contain expected '"+fragment+"'"); + } + /** fails if log _does_ contain the indicated fragment */ + public void assertLogDoesntContain(String fragment) { + for (Record r: messages) { + if (r.getMessage()!=null && r.getMessage().contains(fragment)) + throw new AssertionFailedError("log contained unexpected '"+fragment+"'"); + } + } + + /** throws AssertionFailedError if the log does not contain the indicated fragment; + * otherwise returns a record which does satisfy the constraint + */ + public Record assertLogContains(Predicate test) { + for (Record r: messages) { + if (r.getMessage()!=null && test.apply(r)) return r; + } + throw new AssertionFailedError("log did not contain any records satisfying expected predicate"); + } + + @Override + public String getCategory() { + return category; + } + + public void setLevel(Level level) { + this.level = level; + } + public void setAllLevelsEnabled() { + level = Level.ALL; + } + public void setAllLevelsDisabled() { + level = Level.OFF; + } + + @Override + public boolean isTraceEnabled() { + return level.intValue() <= Level.FINER.intValue(); + } + @Override + public boolean isDebugEnabled() { + return level.intValue() <= Level.FINE.intValue(); + } + + @Override + public boolean isInfoEnabled() { + return level.intValue() <= Level.INFO.intValue(); + } + + @Override + public boolean isWarnEnabled() { + return level.intValue() <= Level.WARNING.intValue(); + } + + @Override + public boolean isErrorEnabled() { + return level.intValue() <= Level.SEVERE.intValue(); + } + + + @Override + protected void logError(String message, Throwable e) { + getMessages().add(new Record(Level.SEVERE, message, e)); + } + + @Override + protected void logError(String message) { + getMessages().add(new Record(Level.SEVERE, message, null)); + } + + @Override + protected void logWarn(String message, Throwable e) { + getMessages().add(new Record(Level.WARNING, message, e)); + } + + @Override + protected void logWarn(String message) { + getMessages().add(new Record(Level.WARNING, message, null)); + } + + @Override + protected void logInfo(String message) { + getMessages().add(new Record(Level.INFO, message, null)); + } + + @Override + protected void logDebug(String message) { + getMessages().add(new Record(Level.FINE, message, null)); + } + + @Override + protected void logTrace(String message) { + getMessages().add(new Record(Level.FINER, message, null)); + } + +} diff --git a/core/src/test/java/org/jclouds/logging/BufferLoggerTest.java b/core/src/test/java/org/jclouds/logging/BufferLoggerTest.java new file mode 100644 index 0000000000..b054c8d07d --- /dev/null +++ b/core/src/test/java/org/jclouds/logging/BufferLoggerTest.java @@ -0,0 +1,31 @@ +package org.jclouds.logging; + +import java.util.logging.Level; + +import org.jclouds.logging.BufferLogger.Record; +import org.testng.Assert; +import org.testng.annotations.Test; + +@Test +public class BufferLoggerTest { + + public void testLogCapturesRightMessages() { + BufferLogger b = new BufferLogger("foo"); + b.setLevel(Level.INFO); + b.info("hi 1"); + b.error(new Throwable("check"), "hi 2"); + b.debug("hi 3 nope"); + + Record r; + r = b.assertLogContains("hi 1"); + Assert.assertEquals(Level.INFO, r.getLevel()); + Assert.assertNull(r.getTrace()); + + r = b.assertLogContains("hi 2"); + Assert.assertEquals(Level.SEVERE, r.getLevel()); + Assert.assertEquals(r.getTrace().getMessage(), "check"); + + b.assertLogDoesntContain("hi 3"); + } + +} From 067ed6d6ce48cef0096d7d74037f87e97d876d89 Mon Sep 17 00:00:00 2001 From: Alex Heneveld Date: Wed, 30 Nov 2011 18:27:16 +0000 Subject: [PATCH 5/5] test for 738, downgrading some warnings to info --- .../org/jclouds/sshj/SshjSshClientTest.java | 33 +++++++++++++++++++ 1 file changed, 33 insertions(+) diff --git a/drivers/sshj/src/test/java/org/jclouds/sshj/SshjSshClientTest.java b/drivers/sshj/src/test/java/org/jclouds/sshj/SshjSshClientTest.java index e94f0dd201..9b5a130b46 100644 --- a/drivers/sshj/src/test/java/org/jclouds/sshj/SshjSshClientTest.java +++ b/drivers/sshj/src/test/java/org/jclouds/sshj/SshjSshClientTest.java @@ -29,6 +29,7 @@ import java.io.IOException; import java.net.ConnectException; import java.net.SocketTimeoutException; import java.util.Properties; +import java.util.logging.Level; import net.schmizz.sshj.SSHClient; import net.schmizz.sshj.common.SSHException; @@ -37,11 +38,14 @@ import net.schmizz.sshj.transport.TransportException; import net.schmizz.sshj.userauth.UserAuthException; import org.jclouds.domain.Credentials; +import org.jclouds.logging.BufferLogger; +import org.jclouds.logging.BufferLogger.Record; import org.jclouds.logging.slf4j.config.SLF4JLoggingModule; import org.jclouds.net.IPSocket; import org.jclouds.rest.AuthorizationException; import org.jclouds.ssh.SshClient; import org.jclouds.sshj.config.SshjSshClientModule; +import org.testng.Assert; import org.testng.annotations.BeforeTest; import org.testng.annotations.Test; @@ -179,4 +183,33 @@ public class SshjSshClientTest { assert !ssh1.shouldRetry(new RuntimeException(nex)); } + public void testRetriesLoggedAtInfoWithCount() throws Exception { + @SuppressWarnings("unchecked") + SshjSshClient.Connection mockConnection = createMock(SshjSshClient.Connection.class); + net.schmizz.sshj.SSHClient mockClient = createMock(net.schmizz.sshj.SSHClient.class); + + mockConnection.clear(); expectLastCall(); + mockConnection.create(); expectLastCall().andThrow(new ConnectionException("test1")); + mockConnection.clear(); expectLastCall(); + //currently does two clears, one on failure (above) and one on next iteration (below) + mockConnection.clear(); expectLastCall(); + mockConnection.create(); expectLastCall().andReturn(mockClient); + replay(mockConnection); + replay(mockClient); + + ssh.sshConnection = mockConnection; + BufferLogger logcheck = new BufferLogger(ssh.getClass().getCanonicalName()); + ssh.logger = logcheck; + logcheck.setLevel(Level.INFO); + + ssh.connect(); + + Assert.assertEquals(ssh.ssh, mockClient); + verify(mockConnection); + verify(mockClient); + Record r = logcheck.assertLogContains("attempt 1 of 5"); + logcheck.assertLogDoesntContain("attempt 2 of 5"); + Assert.assertEquals(Level.INFO, r.getLevel()); + } + }