make logs less chatty

#80
This commit is contained in:
Shikhar Bhushan
2012-07-05 00:10:40 +05:30
parent 4fb56b868f
commit 732de2b605
22 changed files with 52 additions and 52 deletions

View File

@@ -96,7 +96,7 @@ public class DefaultConfig
private final Logger log = LoggerFactory.getLogger(getClass());
private static final String VERSION = "SSHJ_0_8";
private static final String VERSION = "SSHJ_0_9_SNAPSHOT";
public DefaultConfig() {
setVersion(VERSION);

View File

@@ -683,7 +683,7 @@ public class SSHClient
final long start = System.currentTimeMillis();
trans.doKex();
log.info("Key exchange took {} seconds", (System.currentTimeMillis() - start) / 1000.0);
log.debug("Key exchange took {} seconds", (System.currentTimeMillis() - start) / 1000.0);
}
/**

View File

@@ -62,11 +62,11 @@ public class SecurityUtils {
public void run()
throws Exception {
if (java.security.Security.getProvider(BOUNCY_CASTLE) == null) {
LOG.info("Trying to register BouncyCastle as a JCE provider");
LOG.debug("Trying to register BouncyCastle as a JCE provider");
java.security.Security.addProvider(new BouncyCastleProvider());
MessageDigest.getInstance("MD5", BOUNCY_CASTLE);
KeyAgreement.getInstance("DH", BOUNCY_CASTLE);
LOG.info("Registration succeeded");
LOG.info("BouncyCastle registration succeeded");
} else
LOG.info("BouncyCastle already registered as a JCE provider");
securityProvider = BOUNCY_CASTLE;

View File

@@ -136,7 +136,7 @@ public class StreamCopier {
final double timeSeconds = (System.currentTimeMillis() - startTime) / 1000.0;
final double sizeKiB = count / 1024.0;
log.info("{} KiB transferred in {} seconds ({} KiB/s)", new Object[] { sizeKiB, timeSeconds, (sizeKiB / timeSeconds) });
log.debug("{} KiB transferred in {} seconds ({} KiB/s)", new Object[] { sizeKiB, timeSeconds, (sizeKiB / timeSeconds) });
if (length != -1 && read == -1)
throw new IOException("Encountered EOF, could not transfer " + length + " bytes");

View File

@@ -65,7 +65,7 @@ public class ConnectionImpl
@Override
public void attach(Channel chan) {
log.info("Attaching `{}` channel (#{})", chan.getType(), chan.getID());
log.debug("Attaching `{}` channel (#{})", chan.getType(), chan.getID());
channels.put(chan.getID(), chan);
}
@@ -81,7 +81,7 @@ public class ConnectionImpl
@Override
public void forget(Channel chan) {
log.info("Forgetting `{}` channel (#{})", chan.getType(), chan.getID());
log.debug("Forgetting `{}` channel (#{})", chan.getType(), chan.getID());
channels.remove(chan.getID());
synchronized (internalSynchronizer) {
if (channels.isEmpty())
@@ -91,13 +91,13 @@ public class ConnectionImpl
@Override
public void forget(ForwardedChannelOpener opener) {
log.info("Forgetting opener for `{}` channels: {}", opener.getChannelType(), opener);
log.debug("Forgetting opener for `{}` channels: {}", opener.getChannelType(), opener);
openers.remove(opener.getChannelType());
}
@Override
public void attach(ForwardedChannelOpener opener) {
log.info("Attaching opener for `{}` channels: {}", opener.getChannelType(), opener);
log.debug("Attaching opener for `{}` channels: {}", opener.getChannelType(), opener);
openers.put(opener.getChannelType(), opener);
}
@@ -187,7 +187,7 @@ public class ConnectionImpl
byte[] specifics)
throws TransportException {
synchronized (globalReqPromises) {
log.info("Making global request for `{}`", name);
log.debug("Making global request for `{}`", name);
trans.write(new SSHPacket(Message.GLOBAL_REQUEST).putString(name)
.putBoolean(wantReply)
.putRawBytes(specifics));

View File

@@ -122,7 +122,7 @@ public abstract class AbstractChannel
this.recipient = recipient;
rwin = new Window.Remote(remoteWinSize, (int) Math.min(remoteMaxPacketSize, REMOTE_MAX_PACKET_SIZE_CEILING));
out = new ChannelOutputStream(this, trans, rwin);
log.info("Initialized - {}", this);
log.debug("Initialized - {}", this);
}
@Override
@@ -220,7 +220,7 @@ public abstract class AbstractChannel
private void gotClose()
throws TransportException {
log.info("Got close");
log.debug("Got close");
try {
closeAllStreams();
sendClose();
@@ -286,7 +286,7 @@ public abstract class AbstractChannel
throws TransportException {
try {
if (!closeRequested) {
log.info("Sending close");
log.debug("Sending close");
trans.write(newBuffer(Message.CHANNEL_CLOSE));
}
} finally {
@@ -313,7 +313,7 @@ public abstract class AbstractChannel
} catch (Buffer.BufferException be) {
throw new ConnectionException(be);
}
log.info("Got chan request for `{}`", reqType);
log.debug("Got chan request for `{}`", reqType);
handleRequest(reqType, buf);
}
@@ -325,7 +325,7 @@ public abstract class AbstractChannel
} catch (Buffer.BufferException be) {
throw new ConnectionException(be);
}
log.info("Received window adjustment for {} bytes", howMuch);
log.debug("Received window adjustment for {} bytes", howMuch);
rwin.expand(howMuch);
}
@@ -371,7 +371,7 @@ public abstract class AbstractChannel
protected Event<ConnectionException> sendChannelRequest(String reqType, boolean wantReply,
Buffer.PlainBuffer reqSpecific)
throws TransportException {
log.info("Sending channel request for `{}`", reqType);
log.debug("Sending channel request for `{}`", reqType);
synchronized (chanReqResponseEvents) {
trans.write(
newBuffer(Message.CHANNEL_REQUEST)
@@ -407,7 +407,7 @@ public abstract class AbstractChannel
private synchronized void gotEOF()
throws TransportException {
log.info("Got EOF");
log.debug("Got EOF");
eofGot = true;
eofInputStreams();
if (eofSent)
@@ -424,7 +424,7 @@ public abstract class AbstractChannel
throws TransportException {
try {
if (!closeRequested && !eofSent) {
log.info("Sending EOF");
log.debug("Sending EOF");
trans.write(newBuffer(Message.CHANNEL_EOF));
if (eofGot)
sendClose();

View File

@@ -161,7 +161,7 @@ public final class ChannelInputStream
synchronized (win) {
final long adjustment = win.neededAdjustment();
if (adjustment > 0) {
log.info("Sending SSH_MSG_CHANNEL_WINDOW_ADJUST to #{} for {} bytes", chan.getRecipient(), adjustment);
log.debug("Sending SSH_MSG_CHANNEL_WINDOW_ADJUST to #{} for {} bytes", chan.getRecipient(), adjustment);
trans.write(new SSHPacket(Message.CHANNEL_WINDOW_ADJUST)
.putUInt32(chan.getRecipient()).putUInt32(adjustment));
win.expand(adjustment);

View File

@@ -129,10 +129,10 @@ public class LocalPortForwarder {
log.info("Listening on {}", serverSocket.getLocalSocketAddress());
while (!Thread.currentThread().isInterrupted()) {
final Socket socket = serverSocket.accept();
log.info("Got connection from {}", socket.getRemoteSocketAddress());
log.debug("Got connection from {}", socket.getRemoteSocketAddress());
openChannel(socket).start();
}
log.info("Interrupted!");
log.debug("Interrupted!");
}
}

View File

@@ -66,7 +66,7 @@ public abstract class AbstractForwardedChannel
@Override
public void confirm()
throws TransportException {
log.info("Confirming `{}` channel #{}", getType(), getID());
log.debug("Confirming `{}` channel #{}", getType(), getID());
// Must ensure channel is attached before confirming, data could start coming in immediately!
conn.attach(this);
trans.write(newBuffer(Message.CHANNEL_OPEN_CONFIRMATION)
@@ -79,7 +79,7 @@ public abstract class AbstractForwardedChannel
@Override
public void reject(Reason reason, String message)
throws TransportException {
log.info("Rejecting `{}` channel: {}", getType(), message);
log.debug("Rejecting `{}` channel: {}", getType(), message);
conn.sendOpenFailure(getRecipient(), reason, message);
}

View File

@@ -44,7 +44,7 @@ public class SocketForwardingConnectListener
@Override
public void gotConnect(Channel.Forwarded chan)
throws IOException {
log.info("New connection from {}:{}", chan.getOriginatorIP(), chan.getOriginatorPort());
log.debug("New connection from {}:{}", chan.getOriginatorIP(), chan.getOriginatorPort());
final Socket sock = new Socket();
sock.setSendBufferSize(chan.getLocalMaxPacketSize());

View File

@@ -48,7 +48,7 @@ public abstract class RemoteResource
@Override
public void close()
throws IOException {
log.info("Closing `{}`", this);
log.debug("Closing `{}`", this);
requester.doRequest(newRequest(PacketType.CLOSE)).ensureStatusPacketIsOK();
}

View File

@@ -81,7 +81,7 @@ public class SFTPEngine
throw new SFTPException("Expected INIT packet, received: " + type);
operativeVersion = response.readUInt32AsInt();
log.info("Server version {}", operativeVersion);
log.debug("Server version {}", operativeVersion);
if (MAX_SUPPORTED_VERSION < operativeVersion)
throw new SFTPException("Server reported incompatible protocol version: " + operativeVersion);

View File

@@ -31,7 +31,7 @@ public class StatefulSFTPClient
throws IOException {
super(engine);
this.cwd = getSFTPEngine().canonicalize(".");
log.info("Start dir = {}", cwd);
log.debug("Start dir = {}", cwd);
}
private synchronized String cwdify(String path) {
@@ -44,7 +44,7 @@ public class StatefulSFTPClient
if (statExistence(cwd) == null) {
throw new SFTPException(cwd + ": does not exist");
}
log.info("CWD = {}", cwd);
log.debug("CWD = {}", cwd);
}
public synchronized List<RemoteResourceInfo> ls()

View File

@@ -166,7 +166,7 @@ final class Decoder
}
if (isInvalidPacketLength(len)) { // Check packet length validity
log.info("Error decoding packet (invalid length) {}", inputBuffer.printHex());
log.error("Error decoding packet (invalid length) {}", inputBuffer.printHex());
throw new TransportException(DisconnectReason.PROTOCOL_ERROR, "invalid packet length: " + len);
}

View File

@@ -80,7 +80,7 @@ final class Heartbeater
while (!isInterrupted()) {
final int hi = getPositiveInterval();
if (trans.isRunning()) {
log.info("Sending heartbeat since {} seconds elapsed", hi);
log.debug("Sending heartbeat since {} seconds elapsed", hi);
trans.write(new SSHPacket(Message.IGNORE));
}
Thread.sleep(hi * 1000);

View File

@@ -192,7 +192,7 @@ final class KeyExchanger
*/
private void sendKexInit()
throws TransportException {
log.info("Sending SSH_MSG_KEXINIT");
log.debug("Sending SSH_MSG_KEXINIT");
clientProposal = new Proposal(transport.getConfig());
transport.write(clientProposal.getPacket());
kexInitSent.set();
@@ -200,7 +200,7 @@ final class KeyExchanger
private void sendNewKeys()
throws TransportException {
log.info("Sending SSH_MSG_NEWKEYS");
log.debug("Sending SSH_MSG_NEWKEYS");
transport.write(new SSHPacket(Message.NEWKEYS));
}
@@ -354,7 +354,7 @@ final class KeyExchanger
case KEXINIT:
ensureReceivedMatchesExpected(msg, Message.KEXINIT);
log.info("Received SSH_MSG_KEXINIT");
log.debug("Received SSH_MSG_KEXINIT");
startKex(false); // Will start key exchange if not already on
/*
* We block on this event to prevent a race condition where we may have received a SSH_MSG_KEXINIT before
@@ -367,7 +367,7 @@ final class KeyExchanger
case FOLLOWUP:
ensureKexOngoing();
log.info("Received kex followup data");
log.debug("Received kex followup data");
try {
if (kex.next(msg, buf)) {
verifyHost(kex.getHostKey());
@@ -382,7 +382,7 @@ final class KeyExchanger
case NEWKEYS:
ensureReceivedMatchesExpected(msg, Message.NEWKEYS);
ensureKexOngoing();
log.info("Received SSH_MSG_NEWKEYS");
log.debug("Received SSH_MSG_NEWKEYS");
gotNewKeys();
setKexDone();
expected = Expected.KEXINIT;

View File

@@ -90,7 +90,7 @@ public final class TransportImpl
private final DisconnectListener nullDisconnectListener = new DisconnectListener() {
@Override
public void notifyDisconnect(DisconnectReason reason) {
log.debug("Default disconnect listener - {}", reason);
log.info("Disconnected - {}", reason);
}
};
@@ -299,7 +299,7 @@ public final class TransportImpl
if (service == null)
service = nullService;
log.info("Setting active service to {}", service.getName());
log.debug("Setting active service to {}", service.getName());
this.service = service;
}
@@ -346,7 +346,7 @@ public final class TransportImpl
public long sendUnimplemented()
throws TransportException {
final long seq = decoder.getSequenceNumber();
log.info("Sending SSH_MSG_UNIMPLEMENTED for packet #{}", seq);
log.debug("Sending SSH_MSG_UNIMPLEMENTED for packet #{}", seq);
return write(new SSHPacket(Message.UNIMPLEMENTED).putUInt32(seq));
}
@@ -483,7 +483,7 @@ public final class TransportImpl
break;
}
case IGNORE: {
log.info("Received SSH_MSG_IGNORE");
log.debug("Received SSH_MSG_IGNORE");
break;
}
case UNIMPLEMENTED: {
@@ -508,7 +508,7 @@ public final class TransportImpl
try {
final boolean display = buf.readBoolean();
final String message = buf.readString();
log.info("Received SSH_MSG_DEBUG (display={}) '{}'", display, message);
log.debug("Received SSH_MSG_DEBUG (display={}) '{}'", display, message);
} catch (Buffer.BufferException be) {
throw new TransportException(be);
}
@@ -549,7 +549,7 @@ public final class TransportImpl
private void gotUnimplemented(SSHPacket buf)
throws SSHException {
long seqNum = buf.readUInt32();
log.info("Received SSH_MSG_UNIMPLEMENTED #{}", seqNum);
log.debug("Received SSH_MSG_UNIMPLEMENTED #{}", seqNum);
if (kexer.isKexOngoing())
throw new TransportException("Received SSH_MSG_UNIMPLEMENTED while exchanging keys");
getService().notifyUnimplemented(seqNum);

View File

@@ -107,7 +107,7 @@ public abstract class AbstractDHG
sha1.init();
initDH(dh);
log.info("Sending SSH_MSG_KEXDH_INIT");
log.debug("Sending SSH_MSG_KEXDH_INIT");
trans.write(new SSHPacket(Message.KEXDH_INIT).putMPInt(dh.getE()));
}
@@ -117,7 +117,7 @@ public abstract class AbstractDHG
if (msg != Message.KEXDH_31)
throw new TransportException(DisconnectReason.KEY_EXCHANGE_FAILED, "Unexpected packet: " + msg);
log.info("Received SSH_MSG_KEXDH_REPLY");
log.debug("Received SSH_MSG_KEXDH_REPLY");
final byte[] K_S;
final BigInteger f;
final byte[] sig; // signature sent by server

View File

@@ -82,7 +82,7 @@ public class UserAuthImpl
continue;
}
log.info("Trying `{}` auth...", meth.getName());
log.debug("Trying `{}` auth...", meth.getName());
authenticated.clear();
currentMethod = meth;
@@ -93,13 +93,13 @@ public class UserAuthImpl
authenticated.await(timeout, TimeUnit.SECONDS);
} catch (UserAuthException e) {
log.info("`{}` auth failed", meth.getName());
log.debug("`{}` auth failed", meth.getName());
// Give other methods a shot
saveException(e);
continue;
}
log.info("`{}` auth successful", meth.getName());
log.debug("`{}` auth successful", meth.getName());
trans.setAuthenticated(); // So it can put delayed compression into force if applicable
trans.setService(nextService); // We aren't in charge anymore, next service is
return;

View File

@@ -74,7 +74,7 @@ public class AuthKeyboardInteractive
for (int i = 0; i < numPrompts; i++) {
final String prompt = buf.readString();
final boolean echo = buf.readBoolean();
log.info("Requesting response for challenge `{}`; echo={}", prompt, echo);
log.debug("Requesting response for challenge `{}`; echo={}", prompt, echo);
userReplies[i] = new CharArrWrap(provider.getResponse(prompt, echo));
}
} catch (Buffer.BufferException be) {

View File

@@ -37,7 +37,7 @@ public class AuthPassword
public SSHPacket buildReq()
throws UserAuthException {
final AccountResource accountResource = makeAccountResource();
log.info("Requesting password for {}", accountResource);
log.debug("Requesting password for {}", accountResource);
return super.buildReq() // the generic stuff
.putBoolean(false) // no, we are not responding to a CHANGEREQ
.putSensitiveString(pwdf.reqPassword(accountResource));

View File

@@ -23,20 +23,20 @@ public class LoggingTransferListener
@Override
public TransferListener directory(String name) {
log.info("started transferring directory `{}`", name);
log.debug("started transferring directory `{}`", name);
return new LoggingTransferListener(relPath + name + "/");
}
@Override
public StreamCopier.Listener file(final String name, final long size) {
final String path = relPath + name;
log.info("started transferring file `{}` ({} bytes)", path, size);
log.debug("started transferring file `{}` ({} bytes)", path, size);
return new StreamCopier.Listener() {
@Override
public void reportProgress(long transferred)
throws IOException {
if (log.isDebugEnabled()) {
log.debug("transferred {}% of `{}`", ((transferred * 100) / size), path);
if (log.isTraceEnabled()) {
log.trace("transferred {}% of `{}`", ((transferred * 100) / size), path);
}
}
};