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

* i2psnark: Finish migration to I2P logging to reduce object churn (ticket #673)

Browse Source
This commit is contained in:
zzz
2012-08-03 11:19:52 +00:00
parent 95fb141ad9
commit ccf36abd30
5 changed files with 76 additions and 115 deletions
Download Patch File Download Diff File Expand all files Collapse all files

6
apps/i2psnark/java/src/org/klomp/snark/ConnectionAcceptor.java
View File

@@ -146,7 +146,7 @@ public class ConnectionAcceptor implements Runnable
} }
} else { } else {
if (socket.getPeerDestination().equals(_util.getMyDestination())) { if (socket.getPeerDestination().equals(_util.getMyDestination())) {
_util.debug("Incoming connection from myself", Snark.ERROR); _log.error("Incoming connection from myself");
try { socket.close(); } catch (IOException ioe) {} try { socket.close(); } catch (IOException ioe) {}
continue; continue;
} }
@@ -163,13 +163,13 @@ public class ConnectionAcceptor implements Runnable
catch (I2PException ioe) catch (I2PException ioe)
{ {
if (!socketChanged) { if (!socketChanged) {
_util.debug("Error while accepting: " + ioe, Snark.ERROR); _log.error("Error while accepting", ioe);
stop = true; stop = true;
} }
} }
catch (IOException ioe) catch (IOException ioe)
{ {
_util.debug("Error while accepting: " + ioe, Snark.ERROR); _log.error("Error while accepting", ioe);
stop = true; stop = true;
} }
// catch oom? // catch oom?

34
apps/i2psnark/java/src/org/klomp/snark/I2PSnarkUtil.java
View File

@@ -538,40 +538,6 @@ public class I2PSnarkUtil {
return buf.toString(); return buf.toString();
} }
/** hook between snark's logger and an i2p log */
void debug(String msg, int snarkDebugLevel) {
debug(msg, snarkDebugLevel, null);
}
void debug(String msg, int snarkDebugLevel, Throwable t) {
if (t instanceof OutOfMemoryError) {
try { Thread.sleep(100); } catch (InterruptedException ie) {}
try {
t.printStackTrace();
} catch (Throwable tt) {}
try {
System.out.println("OOM thread: " + Thread.currentThread().getName());
} catch (Throwable tt) {}
}
switch (snarkDebugLevel) {
case 0:
case 1:
_log.error(msg, t);
break;
case 2:
_log.warn(msg, t);
break;
case 3:
case 4:
_log.info(msg, t);
break;
case 5:
case 6:
default:
_log.debug(msg, t);
break;
}
}
private static final String BUNDLE_NAME = "org.klomp.snark.web.messages"; private static final String BUNDLE_NAME = "org.klomp.snark.web.messages";
/** lang in routerconsole.lang property, else current locale */ /** lang in routerconsole.lang property, else current locale */

76
apps/i2psnark/java/src/org/klomp/snark/Snark.java
View File

@@ -35,6 +35,7 @@ import net.i2p.I2PAppContext;
import net.i2p.client.streaming.I2PServerSocket; import net.i2p.client.streaming.I2PServerSocket;
import net.i2p.data.Destination; import net.i2p.data.Destination;
import net.i2p.util.I2PThread; import net.i2p.util.I2PThread;
import net.i2p.util.Log;
/** /**
* Main Snark program startup class. * Main Snark program startup class.
@@ -47,29 +48,6 @@ public class Snark
private final static int MIN_PORT = 6881; private final static int MIN_PORT = 6881;
private final static int MAX_PORT = 6889; private final static int MAX_PORT = 6889;
// Error messages (non-fatal)
public final static int ERROR = 1;
// Warning messages
public final static int WARNING = 2;
// Notices (peer level)
public final static int NOTICE = 3;
// Info messages (protocol policy level)
public final static int INFO = 4;
// Debug info (protocol level)
public final static int DEBUG = 5;
// Very low level stuff (network level)
public final static int ALL = 6;
/**
* What level of debug info to show.
*/
//public static int debug = NOTICE;
// Whether or not to ask the user for commands while sharing // Whether or not to ask the user for commands while sharing
//private static boolean command_interpreter = true; //private static boolean command_interpreter = true;
@@ -255,6 +233,7 @@ public class Snark
private byte[] infoHash; private byte[] infoHash;
private String additionalTrackerURL; private String additionalTrackerURL;
private final I2PSnarkUtil _util; private final I2PSnarkUtil _util;
private final Log _log;
private final PeerCoordinatorSet _peerCoordinatorSet; private final PeerCoordinatorSet _peerCoordinatorSet;
private String trackerProblems; private String trackerProblems;
private int trackerSeenPeers; private int trackerSeenPeers;
@@ -308,6 +287,7 @@ public class Snark
completeListener = complistener; completeListener = complistener;
_util = util; _util = util;
_log = util.getContext().logManager().getLog(Snark.class);
_peerCoordinatorSet = peerCoordinatorSet; _peerCoordinatorSet = peerCoordinatorSet;
acceptor = connectionAcceptor; acceptor = connectionAcceptor;
@@ -318,7 +298,8 @@ public class Snark
activity = "Network setup"; activity = "Network setup";
id = generateID(); id = generateID();
debug("My peer id: " + PeerID.idencode(id), Snark.INFO); if (_log.shouldLog(Log.INFO))
_log.info("My peer id: " + PeerID.idencode(id));
/* /*
* Don't start a tunnel if the torrent isn't going to be started. * Don't start a tunnel if the torrent isn't going to be started.
@@ -403,7 +384,8 @@ public class Snark
try { in.close(); } catch (IOException ioe) {} try { in.close(); } catch (IOException ioe) {}
} }
debug(meta.toString(), INFO); if (_log.shouldLog(Log.INFO))
_log.info(meta.toString());
// When the metainfo torrent was created from an existing file/dir // When the metainfo torrent was created from an existing file/dir
// it already exists. // it already exists.
@@ -464,6 +446,7 @@ public class Snark
{ {
completeListener = complistener; completeListener = complistener;
_util = util; _util = util;
_log = util.getContext().logManager().getLog(Snark.class);
_peerCoordinatorSet = peerCoordinatorSet; _peerCoordinatorSet = peerCoordinatorSet;
acceptor = connectionAcceptor; acceptor = connectionAcceptor;
this.torrent = torrent; this.torrent = torrent;
@@ -531,9 +514,11 @@ public class Snark
fatal("Unable to listen for I2P connections"); fatal("Unable to listen for I2P connections");
else { else {
Destination d = serversocket.getManager().getSession().getMyDestination(); Destination d = serversocket.getManager().getSession().getMyDestination();
debug("Listening on I2P destination " + d.toBase64() + " / " + d.calculateHash().toBase64(), NOTICE); if (_log.shouldLog(Log.INFO))
_log.info("Listening on I2P destination " + d.toBase64() + " / " + d.calculateHash().toBase64());
} }
debug("Starting PeerCoordinator, ConnectionAcceptor, and TrackerClient", NOTICE); if (_log.shouldLog(Log.INFO))
_log.info("Starting PeerCoordinator, ConnectionAcceptor, and TrackerClient");
activity = "Collecting pieces"; activity = "Collecting pieces";
coordinator = new PeerCoordinator(_util, id, infoHash, meta, storage, this, this); coordinator = new PeerCoordinator(_util, id, infoHash, meta, storage, this, this);
if (_peerCoordinatorSet != null) { if (_peerCoordinatorSet != null) {
@@ -573,7 +558,8 @@ public class Snark
} }
trackerclient.start(); trackerclient.start();
} else { } else {
debug("NOT starting TrackerClient???", NOTICE); if (_log.shouldLog(Log.INFO))
_log.info("NOT starting TrackerClient???");
} }
} }
@@ -1017,22 +1003,13 @@ public class Snark
private static void usage() private static void usage()
{ {
System.out.println System.out.println
("Usage: snark [--debug [level]] [--no-commands] [--port <port>]"); ("Usage: snark [--no-commands] [--port <port>]");
System.out.println System.out.println
(" [--eepproxy hostname portnum]"); (" [--eepproxy hostname portnum]");
System.out.println System.out.println
(" [--i2cp routerHost routerPort ['name=val name=val name=val']]"); (" [--i2cp routerHost routerPort ['name=val name=val name=val']]");
System.out.println System.out.println
(" (<url>|<file>)"); (" (<url>|<file>)");
System.out.println
(" --debug\tShows some extra info and stacktraces");
System.out.println
(" level\tHow much debug details to show");
System.out.println
(" \t(defaults to "
+ NOTICE + ", with --debug to "
+ INFO + ", highest level is "
+ ALL + ").");
System.out.println System.out.println
(" --no-commands\tDon't read interactive commands or show usage info."); (" --no-commands\tDon't read interactive commands or show usage info.");
System.out.println System.out.println
@@ -1071,7 +1048,7 @@ public class Snark
*/ */
private void fatal(String s, Throwable t) private void fatal(String s, Throwable t)
{ {
_util.debug(s, ERROR, t); _log.error(s, t);
//System.err.println("snark: " + s + ((t == null) ? "" : (": " + t))); //System.err.println("snark: " + s + ((t == null) ? "" : (": " + t)));
//if (debug >= INFO && t != null) //if (debug >= INFO && t != null)
// t.printStackTrace(); // t.printStackTrace();
@@ -1083,14 +1060,6 @@ public class Snark
throw new RuntimeException(s, t); throw new RuntimeException(s, t);
} }
/**
* Show debug info if debug is true.
*/
private void debug(String s, int level)
{
_util.debug(s, level, null);
}
/** CoordinatorListener - this does nothing */ /** CoordinatorListener - this does nothing */
public void peerChange(PeerCoordinator coordinator, Peer peer) public void peerChange(PeerCoordinator coordinator, Peer peer)
{ {
@@ -1168,9 +1137,10 @@ public class Snark
// + " pieces: "); // + " pieces: ");
checking = true; checking = true;
} }
if (!checking) if (!checking) {
debug("Got " + (checked ? "" : "BAD ") + "piece: " + num, if (_log.shouldLog(Log.INFO))
Snark.INFO); _log.info("Got " + (checked ? "" : "BAD ") + "piece: " + num);
}
} }
public void storageAllChecked(Storage storage) public void storageAllChecked(Storage storage)
@@ -1186,7 +1156,8 @@ public class Snark
public void storageCompleted(Storage storage) public void storageCompleted(Storage storage)
{ {
debug("Completely received " + torrent, Snark.INFO); if (_log.shouldLog(Log.INFO))
_log.info("Completely received " + torrent);
//storage.close(); //storage.close();
//System.out.println("Completely received: " + torrent); //System.out.println("Completely received: " + torrent);
if (completeListener != null) if (completeListener != null)
@@ -1259,7 +1230,8 @@ public class Snark
total += c.getCurrentUploadRate(); total += c.getCurrentUploadRate();
} }
long limit = 1024l * _util.getMaxUpBW(); long limit = 1024l * _util.getMaxUpBW();
debug("Total up bw: " + total + " Limit: " + limit, Snark.NOTICE); if (_log.shouldLog(Log.INFO))
_log.info("Total up bw: " + total + " Limit: " + limit);
return total > limit; return total > limit;
} }

39
apps/i2psnark/java/src/org/klomp/snark/Storage.java
View File

@@ -34,6 +34,7 @@ import java.util.StringTokenizer;
import java.util.concurrent.ConcurrentHashMap; import java.util.concurrent.ConcurrentHashMap;
import net.i2p.crypto.SHA1; import net.i2p.crypto.SHA1;
import net.i2p.util.Log;
import net.i2p.util.SecureFile; import net.i2p.util.SecureFile;
/** /**
@@ -55,6 +56,7 @@ public class Storage
private final StorageListener listener; private final StorageListener listener;
private final I2PSnarkUtil _util; private final I2PSnarkUtil _util;
private final Log _log;
private /* FIXME final FIXME */ BitField bitfield; // BitField to represent the pieces private /* FIXME final FIXME */ BitField bitfield; // BitField to represent the pieces
private int needed; // Number of pieces needed private int needed; // Number of pieces needed
@@ -87,6 +89,7 @@ public class Storage
throws IOException throws IOException
{ {
_util = util; _util = util;
_log = util.getContext().logManager().getLog(Storage.class);
this.metainfo = metainfo; this.metainfo = metainfo;
this.listener = listener; this.listener = listener;
needed = metainfo.getPieces(); needed = metainfo.getPieces();
@@ -110,6 +113,7 @@ public class Storage
throws IOException throws IOException
{ {
_util = util; _util = util;
_log = util.getContext().logManager().getLog(Storage.class);
this.listener = listener; this.listener = listener;
// Create names, rafs and lengths arrays. // Create names, rafs and lengths arrays.
getFiles(baseFile); getFiles(baseFile);
@@ -232,8 +236,9 @@ public class Storage
File[] files = f.listFiles(); File[] files = f.listFiles();
if (files == null) if (files == null)
{ {
_util.debug("WARNING: Skipping '" + f if (_log.shouldLog(Log.WARN))
+ "' not a normal file.", Snark.WARNING); _log.warn("WARNING: Skipping '" + f
+ "' not a normal file.");
return; return;
} }
for (int i = 0; i < files.length; i++) for (int i = 0; i < files.length; i++)
@@ -457,7 +462,8 @@ public class Storage
if (files == null) if (files == null)
{ {
// Create base as file. // Create base as file.
_util.debug("Creating/Checking file: " + base, Snark.NOTICE); if (_log.shouldLog(Log.INFO))
_log.info("Creating/Checking file: " + base);
if (!base.createNewFile() && !base.exists()) if (!base.createNewFile() && !base.exists())
throw new IOException("Could not create file " + base); throw new IOException("Could not create file " + base);
@@ -481,7 +487,8 @@ public class Storage
else else
{ {
// Create base as dir. // Create base as dir.
_util.debug("Creating/Checking directory: " + base, Snark.NOTICE); if (_log.shouldLog(Log.INFO))
_log.info("Creating/Checking directory: " + base);
if (!base.mkdir() && !base.isDirectory()) if (!base.mkdir() && !base.isDirectory())
throw new IOException("Could not create directory " + base); throw new IOException("Could not create directory " + base);
@@ -540,19 +547,22 @@ public class Storage
bitfield = savedBitField; bitfield = savedBitField;
needed = metainfo.getPieces() - bitfield.count(); needed = metainfo.getPieces() - bitfield.count();
_probablyComplete = complete(); _probablyComplete = complete();
_util.debug("Found saved state and files unchanged, skipping check", Snark.NOTICE); if (_log.shouldLog(Log.INFO))
_log.info("Found saved state and files unchanged, skipping check");
} else { } else {
// the following sets the needed variable // the following sets the needed variable
changed = true; changed = true;
checkCreateFiles(false); checkCreateFiles(false);
} }
if (complete()) { if (complete()) {
_util.debug("Torrent is complete", Snark.NOTICE); if (_log.shouldLog(Log.INFO))
_log.info("Torrent is complete");
} else { } else {
// fixme saved priorities // fixme saved priorities
if (files != null) if (files != null)
priorities = new int[files.size()]; priorities = new int[files.size()];
_util.debug("Still need " + needed + " out of " + metainfo.getPieces() + " pieces", Snark.NOTICE); if (_log.shouldLog(Log.INFO))
_log.info("Still need " + needed + " out of " + metainfo.getPieces() + " pieces");
} }
} }
@@ -731,7 +741,7 @@ public class Storage
String msg = "File '" + names[i] + "' exists, but has wrong length (expected " + String msg = "File '" + names[i] + "' exists, but has wrong length (expected " +
lengths[i] + " but found " + length + ") - repairing corruption"; lengths[i] + " but found " + length + ") - repairing corruption";
SnarkManager.instance().addMessage(msg); SnarkManager.instance().addMessage(msg);
_util.debug(msg, Snark.ERROR); _log.error(msg);
changed = true; changed = true;
resume = true; resume = true;
_probablyComplete = false; // to force RW _probablyComplete = false; // to force RW
@@ -844,7 +854,8 @@ public class Storage
*/ */
private void balloonFile(int nr) throws IOException private void balloonFile(int nr) throws IOException
{ {
_util.debug("Ballooning " + nr + ": " + RAFfile[nr], Snark.INFO); if (_log.shouldLog(Log.INFO))
_log.info("Ballooning " + nr + ": " + RAFfile[nr]);
long remaining = lengths[nr]; long remaining = lengths[nr];
final int ZEROBLOCKSIZE = (int) Math.min(remaining, 32*1024); final int ZEROBLOCKSIZE = (int) Math.min(remaining, 32*1024);
byte[] zeros = new byte[ZEROBLOCKSIZE]; byte[] zeros = new byte[ZEROBLOCKSIZE];
@@ -875,7 +886,7 @@ public class Storage
closeRAF(i); closeRAF(i);
} }
} catch (IOException ioe) { } catch (IOException ioe) {
_util.debug("Error closing " + RAFfile[i], Snark.ERROR, ioe); _log.error("Error closing " + RAFfile[i], ioe);
// gobble gobble // gobble gobble
} }
} }
@@ -896,7 +907,8 @@ public class Storage
try { try {
bs = new byte[len]; bs = new byte[len];
} catch (OutOfMemoryError oom) { } catch (OutOfMemoryError oom) {
_util.debug("Out of memory, can't honor request for piece " + piece, Snark.WARNING, oom); if (_log.shouldLog(Log.WARN))
_log.warn("Out of memory, can't honor request for piece " + piece, oom);
return null; return null;
} }
getUncheckedPiece(piece, bs, off, len); getUncheckedPiece(piece, bs, off, len);
@@ -1000,8 +1012,9 @@ public class Storage
if (needed > 0) { if (needed > 0) {
if (listener != null) if (listener != null)
listener.setWantedPieces(this); listener.setWantedPieces(this);
_util.debug("WARNING: Not really done, missing " + needed if (_log.shouldLog(Log.WARN))
+ " pieces", Snark.WARNING); _log.warn("WARNING: Not really done, missing " + needed
+ " pieces");
} }
} }

36
apps/i2psnark/java/src/org/klomp/snark/TrackerClient.java
View File

@@ -397,9 +397,10 @@ public class TrackerClient implements Runnable {
catch (IOException ioe) catch (IOException ioe)
{ {
// Probably not fatal (if it doesn't last to long...) // Probably not fatal (if it doesn't last to long...)
_util.debug if (_log.shouldLog(Log.WARN))
_log.warn
("WARNING: Could not contact tracker at '" ("WARNING: Could not contact tracker at '"
+ tr.announce + "': " + ioe, Snark.WARNING); + tr.announce + "': " + ioe);
tr.trackerProblems = ioe.getMessage(); tr.trackerProblems = ioe.getMessage();
// don't show secondary tracker problems to the user // don't show secondary tracker problems to the user
if (tr.isPrimary) if (tr.isPrimary)
@@ -421,8 +422,9 @@ public class TrackerClient implements Runnable {
} }
} }
} else { } else {
_util.debug("Not announcing to " + tr.announce + " last announce was " + if (_log.shouldLog(Log.INFO))
new Date(tr.lastRequestTime) + " interval is " + DataHelper.formatDuration(tr.interval), Snark.INFO); _log.info("Not announcing to " + tr.announce + " last announce was " +
new Date(tr.lastRequestTime) + " interval is " + DataHelper.formatDuration(tr.interval));
} }
if ((!tr.stop) && maxSeenPeers < tr.seenPeers) if ((!tr.stop) && maxSeenPeers < tr.seenPeers)
maxSeenPeers = tr.seenPeers; maxSeenPeers = tr.seenPeers;
@@ -432,7 +434,8 @@ public class TrackerClient implements Runnable {
if (coordinator.needOutboundPeers() && (meta == null || !meta.isPrivate()) && !stop) { if (coordinator.needOutboundPeers() && (meta == null || !meta.isPrivate()) && !stop) {
Set<PeerID> pids = coordinator.getPEXPeers(); Set<PeerID> pids = coordinator.getPEXPeers();
if (!pids.isEmpty()) { if (!pids.isEmpty()) {
_util.debug("Got " + pids.size() + " from PEX", Snark.INFO); if (_log.shouldLog(Log.INFO))
_log.info("Got " + pids.size() + " from PEX");
List<Peer> peers = new ArrayList(pids.size()); List<Peer> peers = new ArrayList(pids.size());
for (PeerID pID : pids) { for (PeerID pID : pids) {
peers.add(new Peer(pID, snark.getID(), snark.getInfoHash(), snark.getMetaInfo())); peers.add(new Peer(pID, snark.getID(), snark.getInfoHash(), snark.getMetaInfo()));
@@ -448,7 +451,8 @@ public class TrackerClient implements Runnable {
} }
} }
} else { } else {
_util.debug("Not getting PEX peers", Snark.INFO); if (_log.shouldLog(Log.INFO))
_log.info("Not getting PEX peers");
} }
// Get peers from DHT // Get peers from DHT
@@ -460,12 +464,14 @@ public class TrackerClient implements Runnable {
else else
numwant = _util.getMaxConnections(); numwant = _util.getMaxConnections();
List<Hash> hashes = _util.getDHT().getPeers(snark.getInfoHash(), numwant, 2*60*1000); List<Hash> hashes = _util.getDHT().getPeers(snark.getInfoHash(), numwant, 2*60*1000);
_util.debug("Got " + hashes + " from DHT", Snark.INFO); if (_log.shouldLog(Log.INFO))
_log.info("Got " + hashes + " from DHT");
// announce ourselves while the token is still good // announce ourselves while the token is still good
// FIXME this needs to be in its own thread // FIXME this needs to be in its own thread
if (!stop) { if (!stop) {
int good = _util.getDHT().announce(snark.getInfoHash(), 8, 5*60*1000); int good = _util.getDHT().announce(snark.getInfoHash(), 8, 5*60*1000);
_util.debug("Sent " + good + " good announces to DHT", Snark.INFO); if (_log.shouldLog(Log.INFO))
_log.info("Sent " + good + " good announces to DHT");
} }
// now try these peers // now try these peers
@@ -486,7 +492,8 @@ public class TrackerClient implements Runnable {
} }
} }
} else { } else {
_util.debug("Not getting DHT peers", Snark.INFO); if (_log.shouldLog(Log.INFO))
_log.info("Not getting DHT peers");
} }
@@ -497,7 +504,8 @@ public class TrackerClient implements Runnable {
return; return;
if (!runStarted) if (!runStarted)
_util.debug(" Retrying in one minute...", Snark.DEBUG); if (_log.shouldLog(Log.DEBUG))
_log.debug(" Retrying in one minute...");
try { try {
// Sleep some minutes... // Sleep some minutes...
@@ -526,7 +534,7 @@ public class TrackerClient implements Runnable {
} // try } // try
catch (Throwable t) catch (Throwable t)
{ {
_util.debug("TrackerClient: " + t, Snark.ERROR, t); _log.error("TrackerClient: " + t, t);
if (t instanceof OutOfMemoryError) if (t instanceof OutOfMemoryError)
throw (OutOfMemoryError)t; throw (OutOfMemoryError)t;
} }
@@ -619,7 +627,8 @@ public class TrackerClient implements Runnable {
else else
buf.append(_util.getMaxConnections()); buf.append(_util.getMaxConnections());
String s = buf.toString(); String s = buf.toString();
_util.debug("Sending TrackerClient request: " + s, Snark.INFO); if (_log.shouldLog(Log.INFO))
_log.info("Sending TrackerClient request: " + s);
tr.lastRequestTime = System.currentTimeMillis(); tr.lastRequestTime = System.currentTimeMillis();
// Don't wait for a response to stopped when shutting down // Don't wait for a response to stopped when shutting down
@@ -635,7 +644,8 @@ public class TrackerClient implements Runnable {
TrackerInfo info = new TrackerInfo(in, snark.getID(), TrackerInfo info = new TrackerInfo(in, snark.getID(),
snark.getInfoHash(), snark.getMetaInfo()); snark.getInfoHash(), snark.getMetaInfo());
_util.debug("TrackerClient response: " + info, Snark.INFO); if (_log.shouldLog(Log.INFO))
_log.info("TrackerClient response: " + info);
String failure = info.getFailureReason(); String failure = info.getFailureReason();
if (failure != null) if (failure != null)