From ccf36abd30861566ef9abd974c2fa372ea623e86 Mon Sep 17 00:00:00 2001 From: zzz <zzz@mail.i2p> Date: Fri, 3 Aug 2012 11:19:52 +0000 Subject: [PATCH] * i2psnark: Finish migration to I2P logging to reduce object churn (ticket #673) --- .../org/klomp/snark/ConnectionAcceptor.java | 6 +- .../src/org/klomp/snark/I2PSnarkUtil.java | 34 --------- .../java/src/org/klomp/snark/Snark.java | 76 ++++++------------- .../java/src/org/klomp/snark/Storage.java | 39 ++++++---- .../src/org/klomp/snark/TrackerClient.java | 36 +++++---- 5 files changed, 76 insertions(+), 115 deletions(-) diff --git a/apps/i2psnark/java/src/org/klomp/snark/ConnectionAcceptor.java b/apps/i2psnark/java/src/org/klomp/snark/ConnectionAcceptor.java index 182d830bfb..686abd9033 100644 --- a/apps/i2psnark/java/src/org/klomp/snark/ConnectionAcceptor.java +++ b/apps/i2psnark/java/src/org/klomp/snark/ConnectionAcceptor.java @@ -146,7 +146,7 @@ public class ConnectionAcceptor implements Runnable } } else { 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) {} continue; } @@ -163,13 +163,13 @@ public class ConnectionAcceptor implements Runnable catch (I2PException ioe) { if (!socketChanged) { - _util.debug("Error while accepting: " + ioe, Snark.ERROR); + _log.error("Error while accepting", ioe); stop = true; } } catch (IOException ioe) { - _util.debug("Error while accepting: " + ioe, Snark.ERROR); + _log.error("Error while accepting", ioe); stop = true; } // catch oom? diff --git a/apps/i2psnark/java/src/org/klomp/snark/I2PSnarkUtil.java b/apps/i2psnark/java/src/org/klomp/snark/I2PSnarkUtil.java index 229132a7fc..b6f8a43c99 100644 --- a/apps/i2psnark/java/src/org/klomp/snark/I2PSnarkUtil.java +++ b/apps/i2psnark/java/src/org/klomp/snark/I2PSnarkUtil.java @@ -538,40 +538,6 @@ public class I2PSnarkUtil { 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"; /** lang in routerconsole.lang property, else current locale */ diff --git a/apps/i2psnark/java/src/org/klomp/snark/Snark.java b/apps/i2psnark/java/src/org/klomp/snark/Snark.java index 1cb344c5e8..c1f088f6e4 100644 --- a/apps/i2psnark/java/src/org/klomp/snark/Snark.java +++ b/apps/i2psnark/java/src/org/klomp/snark/Snark.java @@ -35,6 +35,7 @@ import net.i2p.I2PAppContext; import net.i2p.client.streaming.I2PServerSocket; import net.i2p.data.Destination; import net.i2p.util.I2PThread; +import net.i2p.util.Log; /** * Main Snark program startup class. @@ -47,29 +48,6 @@ public class Snark private final static int MIN_PORT = 6881; 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 //private static boolean command_interpreter = true; @@ -255,6 +233,7 @@ public class Snark private byte[] infoHash; private String additionalTrackerURL; private final I2PSnarkUtil _util; + private final Log _log; private final PeerCoordinatorSet _peerCoordinatorSet; private String trackerProblems; private int trackerSeenPeers; @@ -308,6 +287,7 @@ public class Snark completeListener = complistener; _util = util; + _log = util.getContext().logManager().getLog(Snark.class); _peerCoordinatorSet = peerCoordinatorSet; acceptor = connectionAcceptor; @@ -318,7 +298,8 @@ public class Snark activity = "Network setup"; 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. @@ -403,7 +384,8 @@ public class Snark 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 // it already exists. @@ -464,6 +446,7 @@ public class Snark { completeListener = complistener; _util = util; + _log = util.getContext().logManager().getLog(Snark.class); _peerCoordinatorSet = peerCoordinatorSet; acceptor = connectionAcceptor; this.torrent = torrent; @@ -531,9 +514,11 @@ public class Snark fatal("Unable to listen for I2P connections"); else { 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"; coordinator = new PeerCoordinator(_util, id, infoHash, meta, storage, this, this); if (_peerCoordinatorSet != null) { @@ -573,7 +558,8 @@ public class Snark } trackerclient.start(); } 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() { System.out.println - ("Usage: snark [--debug [level]] [--no-commands] [--port <port>]"); + ("Usage: snark [--no-commands] [--port <port>]"); System.out.println (" [--eepproxy hostname portnum]"); System.out.println (" [--i2cp routerHost routerPort ['name=val name=val name=val']]"); System.out.println (" (<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 (" --no-commands\tDon't read interactive commands or show usage info."); System.out.println @@ -1071,7 +1048,7 @@ public class Snark */ private void fatal(String s, Throwable t) { - _util.debug(s, ERROR, t); + _log.error(s, t); //System.err.println("snark: " + s + ((t == null) ? "" : (": " + t))); //if (debug >= INFO && t != null) // t.printStackTrace(); @@ -1083,14 +1060,6 @@ public class Snark 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 */ public void peerChange(PeerCoordinator coordinator, Peer peer) { @@ -1168,9 +1137,10 @@ public class Snark // + " pieces: "); checking = true; } - if (!checking) - debug("Got " + (checked ? "" : "BAD ") + "piece: " + num, - Snark.INFO); + if (!checking) { + if (_log.shouldLog(Log.INFO)) + _log.info("Got " + (checked ? "" : "BAD ") + "piece: " + num); + } } public void storageAllChecked(Storage storage) @@ -1186,7 +1156,8 @@ public class Snark public void storageCompleted(Storage storage) { - debug("Completely received " + torrent, Snark.INFO); + if (_log.shouldLog(Log.INFO)) + _log.info("Completely received " + torrent); //storage.close(); //System.out.println("Completely received: " + torrent); if (completeListener != null) @@ -1259,7 +1230,8 @@ public class Snark total += c.getCurrentUploadRate(); } 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; } diff --git a/apps/i2psnark/java/src/org/klomp/snark/Storage.java b/apps/i2psnark/java/src/org/klomp/snark/Storage.java index 0dc5f0958e..a17e1bde68 100644 --- a/apps/i2psnark/java/src/org/klomp/snark/Storage.java +++ b/apps/i2psnark/java/src/org/klomp/snark/Storage.java @@ -34,6 +34,7 @@ import java.util.StringTokenizer; import java.util.concurrent.ConcurrentHashMap; import net.i2p.crypto.SHA1; +import net.i2p.util.Log; import net.i2p.util.SecureFile; /** @@ -55,6 +56,7 @@ public class Storage private final StorageListener listener; private final I2PSnarkUtil _util; + private final Log _log; private /* FIXME final FIXME */ BitField bitfield; // BitField to represent the pieces private int needed; // Number of pieces needed @@ -87,6 +89,7 @@ public class Storage throws IOException { _util = util; + _log = util.getContext().logManager().getLog(Storage.class); this.metainfo = metainfo; this.listener = listener; needed = metainfo.getPieces(); @@ -110,6 +113,7 @@ public class Storage throws IOException { _util = util; + _log = util.getContext().logManager().getLog(Storage.class); this.listener = listener; // Create names, rafs and lengths arrays. getFiles(baseFile); @@ -232,8 +236,9 @@ public class Storage File[] files = f.listFiles(); if (files == null) { - _util.debug("WARNING: Skipping '" + f - + "' not a normal file.", Snark.WARNING); + if (_log.shouldLog(Log.WARN)) + _log.warn("WARNING: Skipping '" + f + + "' not a normal file."); return; } for (int i = 0; i < files.length; i++) @@ -457,7 +462,8 @@ public class Storage if (files == null) { // 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()) throw new IOException("Could not create file " + base); @@ -481,7 +487,8 @@ public class Storage else { // 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()) throw new IOException("Could not create directory " + base); @@ -540,19 +547,22 @@ public class Storage bitfield = savedBitField; needed = metainfo.getPieces() - bitfield.count(); _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 { // the following sets the needed variable changed = true; checkCreateFiles(false); } if (complete()) { - _util.debug("Torrent is complete", Snark.NOTICE); + if (_log.shouldLog(Log.INFO)) + _log.info("Torrent is complete"); } else { // fixme saved priorities if (files != null) 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 " + lengths[i] + " but found " + length + ") - repairing corruption"; SnarkManager.instance().addMessage(msg); - _util.debug(msg, Snark.ERROR); + _log.error(msg); changed = true; resume = true; _probablyComplete = false; // to force RW @@ -844,7 +854,8 @@ public class Storage */ 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]; final int ZEROBLOCKSIZE = (int) Math.min(remaining, 32*1024); byte[] zeros = new byte[ZEROBLOCKSIZE]; @@ -875,7 +886,7 @@ public class Storage closeRAF(i); } } catch (IOException ioe) { - _util.debug("Error closing " + RAFfile[i], Snark.ERROR, ioe); + _log.error("Error closing " + RAFfile[i], ioe); // gobble gobble } } @@ -896,7 +907,8 @@ public class Storage try { bs = new byte[len]; } 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; } getUncheckedPiece(piece, bs, off, len); @@ -1000,8 +1012,9 @@ public class Storage if (needed > 0) { if (listener != null) listener.setWantedPieces(this); - _util.debug("WARNING: Not really done, missing " + needed - + " pieces", Snark.WARNING); + if (_log.shouldLog(Log.WARN)) + _log.warn("WARNING: Not really done, missing " + needed + + " pieces"); } } diff --git a/apps/i2psnark/java/src/org/klomp/snark/TrackerClient.java b/apps/i2psnark/java/src/org/klomp/snark/TrackerClient.java index c2b463fd43..349bbe02b7 100644 --- a/apps/i2psnark/java/src/org/klomp/snark/TrackerClient.java +++ b/apps/i2psnark/java/src/org/klomp/snark/TrackerClient.java @@ -397,9 +397,10 @@ public class TrackerClient implements Runnable { catch (IOException ioe) { // 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 '" - + tr.announce + "': " + ioe, Snark.WARNING); + + tr.announce + "': " + ioe); tr.trackerProblems = ioe.getMessage(); // don't show secondary tracker problems to the user if (tr.isPrimary) @@ -421,8 +422,9 @@ public class TrackerClient implements Runnable { } } } else { - _util.debug("Not announcing to " + tr.announce + " last announce was " + - new Date(tr.lastRequestTime) + " interval is " + DataHelper.formatDuration(tr.interval), Snark.INFO); + if (_log.shouldLog(Log.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) maxSeenPeers = tr.seenPeers; @@ -432,7 +434,8 @@ public class TrackerClient implements Runnable { if (coordinator.needOutboundPeers() && (meta == null || !meta.isPrivate()) && !stop) { Set<PeerID> pids = coordinator.getPEXPeers(); 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()); for (PeerID pID : pids) { peers.add(new Peer(pID, snark.getID(), snark.getInfoHash(), snark.getMetaInfo())); @@ -448,7 +451,8 @@ public class TrackerClient implements Runnable { } } } else { - _util.debug("Not getting PEX peers", Snark.INFO); + if (_log.shouldLog(Log.INFO)) + _log.info("Not getting PEX peers"); } // Get peers from DHT @@ -460,12 +464,14 @@ public class TrackerClient implements Runnable { else numwant = _util.getMaxConnections(); 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 // FIXME this needs to be in its own thread if (!stop) { 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 @@ -486,7 +492,8 @@ public class TrackerClient implements Runnable { } } } 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; if (!runStarted) - _util.debug(" Retrying in one minute...", Snark.DEBUG); + if (_log.shouldLog(Log.DEBUG)) + _log.debug(" Retrying in one minute..."); try { // Sleep some minutes... @@ -526,7 +534,7 @@ public class TrackerClient implements Runnable { } // try catch (Throwable t) { - _util.debug("TrackerClient: " + t, Snark.ERROR, t); + _log.error("TrackerClient: " + t, t); if (t instanceof OutOfMemoryError) throw (OutOfMemoryError)t; } @@ -619,7 +627,8 @@ public class TrackerClient implements Runnable { else buf.append(_util.getMaxConnections()); 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(); // 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(), 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(); if (failure != null) -- GitLab