echelon/i2p.i2p
1
0
Fork 0
forked from I2P_Developers/i2p.i2p
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

NTCP2: Reduce log levels

Browse Source
This commit is contained in:
zzz
2018-07-19 14:17:37 +00:00
parent 412fcfb578
commit c35d1583d4
3 changed files with 74 additions and 74 deletions
Download Patch File Download Diff File Expand all files Collapse all files

37
router/java/src/net/i2p/router/transport/ntcp/InboundEstablishState.java
View File

@ -646,8 +646,8 @@ class InboundEstablishState extends EstablishBase implements NTCP2Payload.Payloa
byte options[] = new byte[OPTIONS1_SIZE];
try {
_handshakeState.start();
if (_log.shouldWarn())
_log.warn("After start: " + _handshakeState.toString());
if (_log.shouldDebug())
_log.debug("After start: " + _handshakeState.toString());
_handshakeState.readMessage(_X, 0, MSG1_SIZE, options, 0);
} catch (GeneralSecurityException gse) {
// Read a random number of bytes, store wanted in _padlen1
@ -668,8 +668,8 @@ class InboundEstablishState extends EstablishBase implements NTCP2Payload.Payloa
fail("Bad msg 1, X = " + Base64.encode(_X, 0, KEY_SIZE), re);
return;
}
if (_log.shouldWarn())
_log.warn("After msg 1: " + _handshakeState.toString());
if (_log.shouldDebug())
_log.debug("After msg 1: " + _handshakeState.toString());
int v = options[1] & 0xff;
if (v != NTCPTransport.NTCP2_INT_VERSION) {
fail("Bad version: " + v);
@ -738,8 +738,8 @@ class InboundEstablishState extends EstablishBase implements NTCP2Payload.Payloa
return;
changeState(State.IB_NTCP2_GOT_PADDING);
_handshakeState.mixHash(_X, 0, _padlen1);
if (_log.shouldWarn())
_log.warn("After mixhash padding " + _padlen1 + " msg 1: " + _handshakeState.toString());
if (_log.shouldDebug())
_log.debug("After mixhash padding " + _padlen1 + " msg 1: " + _handshakeState.toString());
_received = 0;
if (src.hasRemaining()) {
// Inbound conn can never have extra data after msg 1
@ -778,8 +778,8 @@ class InboundEstablishState extends EstablishBase implements NTCP2Payload.Payloa
fail("Bad msg 3", re);
return;
}
if (_log.shouldWarn())
_log.warn("After msg 3: " + _handshakeState.toString());
if (_log.shouldDebug())
_log.debug("After msg 3: " + _handshakeState.toString());
try {
// calls callbacks below
NTCP2Payload.processPayload(_context, this, payload, 0, _msg3p2len - MAC_SIZE, true);
@ -840,16 +840,16 @@ class InboundEstablishState extends EstablishBase implements NTCP2Payload.Payloa
fail("Bad msg 2 out", re);
return;
}
if (_log.shouldWarn())
_log.warn("After msg 2: " + _handshakeState.toString());
if (_log.shouldDebug())
_log.debug("After msg 2: " + _handshakeState.toString());
Hash h = _context.routerHash();
SessionKey bobHash = new SessionKey(h.getData());
_context.aes().encrypt(tmp, 0, tmp, 0, bobHash, _prevEncrypted, KEY_SIZE);
if (padlen2 > 0) {
_context.random().nextBytes(tmp, MSG2_SIZE, padlen2);
_handshakeState.mixHash(tmp, MSG2_SIZE, padlen2);
if (_log.shouldWarn())
_log.warn("After mixhash padding " + padlen2 + " msg 2: " + _handshakeState.toString());
if (_log.shouldDebug())
_log.debug("After mixhash padding " + padlen2 + " msg 2: " + _handshakeState.toString());
}
changeState(State.IB_NTCP2_SENT_Y);
@ -872,6 +872,7 @@ class InboundEstablishState extends EstablishBase implements NTCP2Payload.Payloa
CipherStatePair ckp = _handshakeState.split();
CipherState rcvr = ckp.getReceiver();
CipherState sender = ckp.getSender();
// debug, to be removed
byte[] k_ab = rcvr.getKey();
byte[] k_ba = sender.getKey();
@ -885,8 +886,8 @@ class InboundEstablishState extends EstablishBase implements NTCP2Payload.Payloa
_log.warn("Failed msg3p2, code " + _msg3p2FailReason + " for " + this);
_con.failInboundEstablishment(sender, sip_ba, _msg3p2FailReason);
} else {
if (_log.shouldWarn()) {
_log.warn("Finished establishment for " + this +
if (_log.shouldDebug()) {
_log.debug("Finished establishment for " + this +
"\nGenerated ChaCha key for A->B: " + Base64.encode(k_ab) +
"\nGenerated ChaCha key for B->A: " + Base64.encode(k_ba) +
"\nGenerated SipHash key for A->B: " + Base64.encode(sip_ab) +
@ -963,11 +964,11 @@ class InboundEstablishState extends EstablishBase implements NTCP2Payload.Payloa
if (flood && !ri.equals(old)) {
FloodfillNetworkDatabaseFacade fndf = (FloodfillNetworkDatabaseFacade) _context.netDb();
if (fndf.floodConditional(ri)) {
if (_log.shouldLog(Log.WARN))
_log.warn("Flooded the RI: " + h);
if (_log.shouldDebug())
_log.debug("Flooded the RI: " + h);
} else {
if (_log.shouldLog(Log.WARN))
_log.warn("Flood request but we didn't: " + h);
if (_log.shouldInfo())
_log.info("Flood request but we didn't: " + h);
}
}
} catch (IllegalArgumentException iae) {

78
router/java/src/net/i2p/router/transport/ntcp/NTCPConnection.java
View File

@ -892,8 +892,8 @@ public class NTCPConnection implements Closeable {
blocks.add(block);
size += sz;
_nextInfoTime = now + (INFO_FREQUENCY / 2) + _context.random().nextInt(INFO_FREQUENCY);
if (_log.shouldLog(Log.INFO))
_log.info("SENDING NTCP2 RI block");
if (_log.shouldDebug())
_log.debug("SENDING NTCP2 RI block");
} // else wait until next time
}
int availForPad = BUFFER_SIZE - (size + NTCP2Payload.BLOCK_HEADER_SIZE);
@ -936,8 +936,8 @@ public class NTCPConnection implements Closeable {
int padlen = min;
if (range > 0)
padlen += _context.random().nextInt(1 + range);
if (_log.shouldWarn())
_log.warn("Padding params:" +
if (_log.shouldDebug())
_log.debug("Padding params:" +
" data size: " + dataSize +
" avail: " + availForPad +
" minSend: " + minSend +
@ -968,8 +968,8 @@ public class NTCPConnection implements Closeable {
*/
private void sendRouterInfo(RouterInfo ri, boolean shouldFlood) {
// no synch needed, sendNTCP2() is synched
if (_log.shouldWarn())
_log.warn("Sending router info for: " + ri.getHash() + " flood? " + shouldFlood);
if (_log.shouldDebug())
_log.debug("Sending router info for: " + ri.getHash() + " flood? " + shouldFlood);
List<Block> blocks = new ArrayList<Block>(2);
Block block = new NTCP2Payload.RIBlock(ri, shouldFlood);
int size = block.getTotalLength();
@ -1002,8 +1002,8 @@ public class NTCPConnection implements Closeable {
private void sendTermination(int reason, int validFramesRcvd) {
// TODO add param to clear queues?
// no synch needed, sendNTCP2() is synched
if (_log.shouldWarn())
_log.warn("Sending termination, reason: " + reason + ", vaild frames rcvd: " + validFramesRcvd);
if (_log.shouldInfo())
_log.info("Sending termination, reason: " + reason + ", vaild frames rcvd: " + validFramesRcvd);
List<Block> blocks = new ArrayList<Block>(2);
Block block = new NTCP2Payload.TerminationBlock(reason, validFramesRcvd);
int plen = block.getTotalLength();
@ -1033,8 +1033,8 @@ public class NTCPConnection implements Closeable {
*/
private synchronized void sendNTCP2(byte[] tmp, List<Block> blocks) {
if (_sender == null) {
if (_log.shouldWarn())
_log.warn("sender gone", new Exception());
if (_log.shouldInfo())
_log.info("sender gone", new Exception());
return;
}
int payloadlen = NTCP2Payload.writePayload(tmp, 0, blocks);
@ -1053,7 +1053,7 @@ public class NTCPConnection implements Closeable {
long sipIV = SipHashInline.hash24(_sendSipk1, _sendSipk2, _sendSipIV);
enc[0] = (byte) ((framelen >> 8) ^ (sipIV >> 8));
enc[1] = (byte) (framelen ^ sipIV);
if (_log.shouldWarn()) {
if (_log.shouldDebug()) {
StringBuilder buf = new StringBuilder(256);
buf.append("Sending ").append(blocks.size())
.append(" blocks in ").append(framelen)
@ -1061,7 +1061,7 @@ public class NTCPConnection implements Closeable {
for (int i = 0; i < blocks.size(); i++) {
buf.append("\n ").append(i).append(": ").append(blocks.get(i).toString());
}
_log.warn(buf.toString());
_log.debug(buf.toString());
}
_transport.getPumper().wantsWrite(this, enc);
toLong8LE(_sendSipIV, 0, sipIV);
@ -1816,8 +1816,6 @@ public class NTCPConnection implements Closeable {
_sendSipk2 = fromLong8LE(sip_ba, 8);
_sendSipIV = new byte[SIP_IV_LENGTH];
System.arraycopy(sip_ba, 16, _sendSipIV, 0, SIP_IV_LENGTH);
if (_log.shouldWarn())
_log.warn("Send SipHash keys: " + _sendSipk1 + ' ' + _sendSipk2 + ' ' + Base64.encode(_sendSipIV));
_establishState = EstablishBase.VERIFIED;
_establishedOn = _context.clock().now();
_nextMetaTime = Long.MAX_VALUE;
@ -1849,8 +1847,8 @@ public class NTCPConnection implements Closeable {
_sendSipk2 = fromLong8LE(sip_send, 8);
_sendSipIV = new byte[SIP_IV_LENGTH];
System.arraycopy(sip_send, 16, _sendSipIV, 0, SIP_IV_LENGTH);
if (_log.shouldWarn())
_log.warn("Send SipHash keys: " + _sendSipk1 + ' ' + _sendSipk2 + ' ' + Base64.encode(_sendSipIV));
if (_log.shouldDebug())
_log.debug("Send SipHash keys: " + _sendSipk1 + ' ' + _sendSipk2 + ' ' + Base64.encode(_sendSipIV));
_clockSkew = clockSkew;
_establishState = EstablishBase.VERIFIED;
_establishedOn = _context.clock().now();
@ -1892,8 +1890,8 @@ public class NTCPConnection implements Closeable {
_sipk1 = fromLong8LE(keyData, 0);
_sipk2 = fromLong8LE(keyData, 8);
System.arraycopy(keyData, 16, _sipIV, 0, SIP_IV_LENGTH);
if (_log.shouldWarn())
_log.warn("Recv SipHash keys: " + _sipk1 + ' ' + _sipk2 + ' ' + Base64.encode(_sipIV));
if (_log.shouldDebug())
_log.debug("Recv SipHash keys: " + _sipk1 + ' ' + _sipk2 + ' ' + Base64.encode(_sipIV));
}
public void receive(ByteBuffer buf) {
@ -1949,8 +1947,8 @@ public class NTCPConnection implements Closeable {
if (_dataBuf != null && _dataBuf.getData().length == BUFFER_SIZE)
releaseReadBuf(_dataBuf);
if (_framelen > BUFFER_SIZE) {
if (_log.shouldWarn())
_log.warn("Allocating big ByteArray: " + _framelen);
if (_log.shouldInfo())
_log.info("Allocating big ByteArray: " + _framelen);
byte[] data = new byte[_framelen];
_dataBuf = new ByteArray(data);
} else {
@ -1995,8 +1993,8 @@ public class NTCPConnection implements Closeable {
* @return success, false for fatal error (AEAD) only
*/
private boolean decryptAndProcess(byte[] data, int off) {
if (_log.shouldWarn())
_log.warn("Decrypting frame " + _frameCount + " with " + _framelen + " bytes");
if (_log.shouldDebug())
_log.debug("Decrypting frame " + _frameCount + " with " + _framelen + " bytes");
try {
_rcvr.decryptWithAd(null, data, off, data, off, _framelen);
} catch (GeneralSecurityException gse) {
@ -2008,8 +2006,8 @@ public class NTCPConnection implements Closeable {
try {
int blocks = NTCP2Payload.processPayload(_context, this, data, off,
_framelen - OutboundNTCP2State.MAC_SIZE, false);
if (_log.shouldWarn())
_log.warn("Processed " + blocks + " blocks in frame");
if (_log.shouldDebug())
_log.debug("Processed " + blocks + " blocks in frame");
_blockCount += blocks;
} catch (IOException ioe) {
if (_log.shouldWarn())
@ -2038,8 +2036,8 @@ public class NTCPConnection implements Closeable {
//// PayloadCallbacks
public void gotRI(RouterInfo ri, boolean isHandshake, boolean flood) throws DataFormatException {
if (_log.shouldWarn())
_log.warn("Got updated RI");
if (_log.shouldDebug())
_log.debug("Got updated RI");
_messagesRead.incrementAndGet();
try {
Hash h = ri.getHash();
@ -2047,11 +2045,11 @@ public class NTCPConnection implements Closeable {
if (flood && !ri.equals(old)) {
FloodfillNetworkDatabaseFacade fndf = (FloodfillNetworkDatabaseFacade) _context.netDb();
if (fndf.floodConditional(ri)) {
if (_log.shouldLog(Log.WARN))
_log.warn("Flooded the RI: " + h);
if (_log.shouldDebug())
_log.debug("Flooded the RI: " + h);
} else {
if (_log.shouldLog(Log.WARN))
_log.warn("Flood request but we didn't: " + h);
if (_log.shouldInfo())
_log.info("Flood request but we didn't: " + h);
}
}
} catch (IllegalArgumentException iae) {
@ -2060,15 +2058,15 @@ public class NTCPConnection implements Closeable {
}
public void gotDateTime(long time) {
if (_log.shouldWarn())
_log.warn("Got updated datetime block");
if (_log.shouldDebug())
_log.debug("Got updated datetime block");
receiveTimestamp((time + 500) / 1000);
// update skew
}
public void gotI2NP(I2NPMessage msg) {
if (_log.shouldWarn())
_log.warn("Got I2NP msg: " + msg);
if (_log.shouldDebug())
_log.debug("Got I2NP msg: " + msg);
long timeToRecv = 0; // _context.clock().now() - _stateBegin;
int size = 100; // FIXME
_transport.messageReceived(msg, _remotePeer, null, timeToRecv, size);
@ -2093,16 +2091,16 @@ public class NTCPConnection implements Closeable {
NTCP2Options hisPadding = new NTCP2Options(tmin, tmax, rmin, rmax,
tdummy, rdummy, tdelay, rdelay);
_paddingConfig = OUR_PADDING.merge(hisPadding);
if (_log.shouldWarn())
_log.warn("Got padding options:" +
if (_log.shouldDebug())
_log.debug("Got padding options:" +
"\nhis padding options: " + hisPadding +
"\nour padding options: " + OUR_PADDING +
"\nmerged config is: " + _paddingConfig);
}
public void gotTermination(int reason, long lastReceived) {
if (_log.shouldWarn())
_log.warn("Got Termination: " + reason + " total rcvd: " + lastReceived);
if (_log.shouldInfo())
_log.info("Got Termination: " + reason + " total rcvd: " + lastReceived);
_terminated = true;
close();
}
@ -2113,8 +2111,8 @@ public class NTCPConnection implements Closeable {
}
public void gotPadding(int paddingLength, int frameLength) {
if (_log.shouldWarn())
_log.warn("Got " + paddingLength +
if (_log.shouldDebug())
_log.debug("Got " + paddingLength +
" bytes padding in " + frameLength +
" byte frame; ratio: " + (((float) paddingLength) / ((float) frameLength)) +
" configured min: " + _paddingConfig.getRecvMin() +

33
router/java/src/net/i2p/router/transport/ntcp/OutboundNTCP2State.java
View File

@ -216,8 +216,8 @@ class OutboundNTCP2State implements EstablishState {
// output to _tmp
try {
_handshakeState.start();
if (_log.shouldWarn())
_log.warn("After start: " + _handshakeState.toString());
if (_log.shouldDebug())
_log.debug("After start: " + _handshakeState.toString());
_handshakeState.writeMessage(_tmp, 0, options, 0, OPTIONS1_SIZE);
} catch (GeneralSecurityException gse) {
// buffer length error
@ -231,8 +231,8 @@ class OutboundNTCP2State implements EstablishState {
fail("Bad msg 1 out", re);
return;
}
if (_log.shouldWarn())
_log.warn("After msg 1: " + _handshakeState.toString());
if (_log.shouldDebug())
_log.debug("After msg 1: " + _handshakeState.toString());
// encrypt key before writing
_context.aes().encrypt(_tmp, 0, _tmp, 0, _bobHash, _bobIV, KEY_SIZE);
@ -242,8 +242,8 @@ class OutboundNTCP2State implements EstablishState {
if (padlen1 > 0) {
_context.random().nextBytes(_tmp, MSG1_SIZE, padlen1);
_handshakeState.mixHash(_tmp, MSG1_SIZE, padlen1);
if (_log.shouldWarn())
_log.warn("After mixhash padding " + padlen1 + " msg 1: " + _handshakeState.toString());
if (_log.shouldDebug())
_log.debug("After mixhash padding " + padlen1 + " msg 1: " + _handshakeState.toString());
}
changeState(State.OB_SENT_X);
@ -285,8 +285,8 @@ class OutboundNTCP2State implements EstablishState {
fail("Bad msg 2, Y = " + Base64.encode(_tmp, 0, KEY_SIZE), re);
return;
}
if (_log.shouldWarn())
_log.warn("After msg 2: " + _handshakeState.toString());
if (_log.shouldDebug())
_log.debug("After msg 2: " + _handshakeState.toString());
_padlen2 = (int) DataHelper.fromLong(options2, 2, 2);
long tsB = DataHelper.fromLong(options2, 8, 4);
long now = _context.clock().now();
@ -310,8 +310,8 @@ class OutboundNTCP2State implements EstablishState {
return;
if (_padlen2 > 0) {
_handshakeState.mixHash(_tmp, 0, _padlen2);
if (_log.shouldWarn())
_log.warn("After mixhash padding " + _padlen2 + " msg 2: " + _handshakeState.toString());
if (_log.shouldDebug())
_log.debug("After mixhash padding " + _padlen2 + " msg 2: " + _handshakeState.toString());
}
changeState(State.OB_GOT_PADDING);
if (src.hasRemaining()) {
@ -384,11 +384,11 @@ class OutboundNTCP2State implements EstablishState {
return;
}
// send it all at once
if (_log.shouldWarn())
_log.warn("Sending msg3, part 1 is:\n" + net.i2p.util.HexDump.dump(tmp, 0, MSG3P1_SIZE));
if (_log.shouldDebug())
_log.debug("Sending msg3, part 1 is:\n" + net.i2p.util.HexDump.dump(tmp, 0, MSG3P1_SIZE));
_transport.getPumper().wantsWrite(_con, tmp);
if (_log.shouldWarn())
_log.warn("After msg 3: " + _handshakeState.toString());
if (_log.shouldDebug())
_log.debug("After msg 3: " + _handshakeState.toString());
setDataPhase();
}
@ -404,6 +404,7 @@ class OutboundNTCP2State implements EstablishState {
CipherStatePair ckp = _handshakeState.split();
CipherState rcvr = ckp.getReceiver();
CipherState sender = ckp.getSender();
// debug, to be removed
byte[] k_ab = sender.getKey();
byte[] k_ba = rcvr.getKey();
@ -412,8 +413,8 @@ class OutboundNTCP2State implements EstablishState {
byte[] sip_ab = sipkeys[0];
byte[] sip_ba = sipkeys[1];
if (_log.shouldWarn()) {
_log.warn("Finished establishment for " + this +
if (_log.shouldDebug()) {
_log.debug("Finished establishment for " + this +
"\nGenerated ChaCha key for A->B: " + Base64.encode(k_ab) +
"\nGenerated ChaCha key for B->A: " + Base64.encode(k_ba) +
"\nGenerated SipHash key for A->B: " + Base64.encode(sip_ab) +