Changeset c8197b8


Ignore:
Timestamp:
Jan 10, 2016 9:22:22 PM (5 years ago)
Author:
zzz <zzz@…>
Branches:
master
Children:
c546b28
Parents:
3573928
Message:

Tunnels: Fix build request Bloom filter (ticket #1746)
Change from 60s DHS to 60m DBF
Use reply key as filter key, not first part of
encrypted data, to match the specs and hopefully reduce dups
BuildMessageProcessor? cleanups
log and stat tweaks
remove deprecated methods
remove some timing measurements
javadocs

Files:
11 edited

Legend:

Unmodified
Added
Removed
  • core/java/src/net/i2p/data/SessionKey.java

    r3573928 rc8197b8  
    1212/**
    1313 * Defines the SessionKey as defined by the I2P data structure spec.
    14  * A session key is 32byte Integer.
     14 * A session key is a 32 byte Integer.
     15 *
     16 * To create one with random data, use I2PAppContext.keyGenerator().generateSessionKey().
    1517 *
    1618 * @author jrandom
     
    2022
    2123    public final static int KEYSIZE_BYTES = 32;
     24    /** A key with all zeroes in the data */
    2225    public static final SessionKey INVALID_KEY = new SessionKey(new byte[KEYSIZE_BYTES]);
    2326
  • history.txt

    r3573928 rc8197b8  
     12016-01-10 zzz
     2 * Tunnels: Fix build request Bloom filter (ticket #1746)
     3
    142016-01-07 zzz
    25 * Console: Fixed summary bar overflow (ticket #1739)
  • router/java/src/net/i2p/data/i2np/BuildRequestRecord.java

    r3573928 rc8197b8  
    11package net.i2p.data.i2np;
    22
     3import java.util.Date;
     4
    35import net.i2p.I2PAppContext;
     6import net.i2p.data.Base64;
    47import net.i2p.data.ByteArray;
    58import net.i2p.data.DataFormatException;
     
    6972    private static final int OFF_LAYER_KEY = OFF_SEND_IDENT + Hash.HASH_LENGTH;
    7073    private static final int OFF_IV_KEY = OFF_LAYER_KEY + SessionKey.KEYSIZE_BYTES;
    71     private static final int OFF_REPLY_KEY = OFF_IV_KEY + SessionKey.KEYSIZE_BYTES;
     74    public static final int OFF_REPLY_KEY = OFF_IV_KEY + SessionKey.KEYSIZE_BYTES;
    7275    private static final int OFF_REPLY_IV = OFF_REPLY_KEY + SessionKey.KEYSIZE_BYTES;
    7376    private static final int OFF_FLAG = OFF_REPLY_IV + IV_SIZE;
     
    157160
    158161    /**
    159      * Time that the request was sent (ms), truncated to the nearest hour
     162     * Time that the request was sent (ms), truncated to the nearest hour.
     163     * This ignores leap seconds.
    160164     */
    161165    public long readRequestTime() {
     
    264268        // prevent hop identification at top of the hour
    265269        truncatedHour -= ctx.random().nextInt(90*1000);
     270        // this ignores leap seconds
    266271        truncatedHour /= (60l*60l*1000l);
    267272        DataHelper.toLong(buf, OFF_REQ_TIME, 4, truncatedHour);
     
    273278            throw new RuntimeException("foo");
    274279    }
     280
     281    /**
     282     *  @since 0.9.24
     283     */
     284    @Override
     285    public String toString() {
     286        StringBuilder buf = new StringBuilder(256);
     287        buf.append("BRR ");
     288        boolean isIBGW = readIsInboundGateway();
     289        boolean isOBEP = readIsOutboundEndpoint();
     290        if (isIBGW) {
     291            buf.append("IBGW in: ").append(readReceiveTunnelId())
     292               .append(" out ").append(readNextTunnelId());
     293        } else if (isOBEP) {
     294            buf.append("OBEP in: ").append(readReceiveTunnelId());
     295        } else {
     296            buf.append("part. in: ").append(readReceiveTunnelId())
     297               .append(" out: ").append(readNextTunnelId());
     298        }
     299        buf.append(" to: ").append(readNextIdentity())
     300           .append(" layer key: ").append(readLayerKey())
     301           .append(" IV key: ").append(readIVKey())
     302           .append(" reply key: ").append(readReplyKey())
     303           .append(" reply IV: ").append(Base64.encode(readReplyIV()))
     304           .append(" hour: ").append(new Date(readRequestTime()))
     305           .append(" reply msg id: ").append(readReplyMessageId());
     306        // to chase i2pd bug
     307        //buf.append('\n').append(net.i2p.util.HexDump.dump(readReplyKey().getData()));
     308        return buf.toString();
     309    }
    275310}   
  • router/java/src/net/i2p/router/RouterThrottleImpl.java

    r3573928 rc8197b8  
    1515 *
    1616 */
    17 class RouterThrottleImpl implements RouterThrottle {
     17public class RouterThrottleImpl implements RouterThrottle {
    1818    protected final RouterContext _context;
    1919    private final Log _log;
     
    2929    // TODO reduce
    3030    private static final long JOB_LAG_LIMIT_TUNNEL = 500;
    31     private static final String PROP_MAX_TUNNELS = "router.maxParticipatingTunnels";
    32     private static final int DEFAULT_MAX_TUNNELS = 10*1000;
     31    public static final String PROP_MAX_TUNNELS = "router.maxParticipatingTunnels";
     32    public static final int DEFAULT_MAX_TUNNELS = 10*1000;
    3333    private static final String PROP_MAX_PROCESSINGTIME = "router.defaultProcessingTimeThrottle";
    3434    private static final long DEFAULT_REJECT_STARTUP_TIME = 10*60*1000;
  • router/java/src/net/i2p/router/RouterVersion.java

    r3573928 rc8197b8  
    1919    public final static String ID = "Monotone";
    2020    public final static String VERSION = CoreVersion.VERSION;
    21     public final static long BUILD = 21;
     21    public final static long BUILD = 22;
    2222
    2323    /** for example "-test" */
  • router/java/src/net/i2p/router/tunnel/BuildMessageGenerator.java

    r3573928 rc8197b8  
    5555     *
    5656     * @param msg out parameter
     57     * @param peerKey Encrypt using this key.
     58     *                If null, replyRouter and replyTunnel are ignored,
     59     *                and the entire record is filled with random data
    5760     * @throws IllegalArgumentException if hop bigger than config
    5861     */
  • router/java/src/net/i2p/router/tunnel/BuildMessageProcessor.java

    r3573928 rc8197b8  
    1111import net.i2p.data.i2np.EncryptedBuildRecord;
    1212import net.i2p.data.i2np.TunnelBuildMessage;
     13import net.i2p.router.RouterThrottleImpl;
    1314import net.i2p.router.util.DecayingBloomFilter;
    1415import net.i2p.router.util.DecayingHashSet;
    1516import net.i2p.util.Log;
     17import net.i2p.util.SystemVersion;
    1618
    1719/**
     
    1921 * read the enclosed tunnel request, decide how to reply, write the reply,
    2022 * encrypt the reply record, and return a TunnelBuildMessage to forward on to
    21  * the next hop
     23 * the next hop.
     24 *
     25 * There is only one of these.
     26 * Instantiated by BuildHandler.
     27 *
    2228 */
    2329public class BuildMessageProcessor {
     30    private final I2PAppContext ctx;
     31    private final Log log;
    2432    private final DecayingBloomFilter _filter;
    2533   
    2634    public BuildMessageProcessor(I2PAppContext ctx) {
    27         _filter = new DecayingHashSet(ctx, 60*1000, 32, "TunnelBMP");
     35        this.ctx = ctx;
     36        log = ctx.logManager().getLog(getClass());
     37        _filter = selectFilter();
    2838        // all createRateStat in TunnelDispatcher
    2939    }
     40
     41    /**
     42     *  For N typical part tunnels and rejecting 50%, that's 12N requests per hour.
     43     *  This is the equivalent of (12N/600) KBps through the IVValidator filter.
     44     *
     45     *  Target false positive rate is 1E-5 or lower
     46     *
     47     *  @since 0.9.24
     48     */
     49    private DecayingBloomFilter selectFilter() {
     50        long maxMemory = SystemVersion.getMaxMemory();
     51        int m;
     52        if (SystemVersion.isAndroid() || SystemVersion.isARM() || maxMemory < 96*1024*1024L) {
     53            // 32 KB
     54            // appx 500 part. tunnels or 6K req/hr
     55            m = 17;
     56        } else if (ctx.getProperty(RouterThrottleImpl.PROP_MAX_TUNNELS, RouterThrottleImpl.DEFAULT_MAX_TUNNELS) >
     57                   RouterThrottleImpl.DEFAULT_MAX_TUNNELS && maxMemory > 256*1024*1024L) {
     58            // 2 MB
     59            // appx 20K part. tunnels or 240K req/hr
     60            m = 23;
     61        } else if (maxMemory > 256*1024*1024L) {
     62            // 1 MB
     63            // appx 10K part. tunnels or 120K req/hr
     64            m = 22;
     65        } else if (maxMemory > 128*1024*1024L) {
     66            // 512 KB
     67            // appx 5K part. tunnels or 60K req/hr
     68            m = 21;
     69        } else {
     70            // 128 KB
     71            // appx 2K part. tunnels or 24K req/hr
     72            m = 19;
     73        }
     74        if (log.shouldInfo())
     75            log.info("Selected Bloom filter m = " + m);
     76        return new DecayingBloomFilter(ctx, 60*60*1000, 32, "TunnelBMP", m);
     77    }
     78
    3079    /**
    3180     * Decrypt the record targetting us, encrypting all of the other records with the included
     
    3988     * @return the current hop's decrypted record or null on failure
    4089     */
    41     public BuildRequestRecord decrypt(I2PAppContext ctx, TunnelBuildMessage msg, Hash ourHash, PrivateKey privKey) {
    42         Log log = ctx.logManager().getLog(getClass());
     90    public BuildRequestRecord decrypt(TunnelBuildMessage msg, Hash ourHash, PrivateKey privKey) {
    4391        BuildRequestRecord rv = null;
    4492        int ourHop = -1;
    4593        long beforeActualDecrypt = 0;
    4694        long afterActualDecrypt = 0;
    47         long totalEq = 0;
    48         long totalDup = 0;
     95        byte[] ourHashData = ourHash.getData();
    4996        long beforeLoop = System.currentTimeMillis();
    5097        for (int i = 0; i < msg.getRecordCount(); i++) {
    5198            EncryptedBuildRecord rec = msg.getRecord(i);
    5299            int len = BuildRequestRecord.PEER_SIZE;
    53             long beforeEq = System.currentTimeMillis();
    54             boolean eq = DataHelper.eq(ourHash.getData(), 0, rec.getData(), 0, len);
    55             totalEq += System.currentTimeMillis()-beforeEq;
     100            boolean eq = DataHelper.eq(ourHashData, 0, rec.getData(), 0, len);
    56101            if (eq) {
    57                 long beforeIsDup = System.currentTimeMillis();
    58                 boolean isDup = _filter.add(rec.getData(), len, 32);
    59                 totalDup += System.currentTimeMillis()-beforeIsDup;
    60                 if (isDup) {
    61                     if (log.shouldLog(Log.WARN))
    62                         log.debug(msg.getUniqueId() + ": A record matching our hash was found, but it seems to be a duplicate");
    63                     ctx.statManager().addRateData("tunnel.buildRequestDup", 1);
    64                     return null;
    65                 }
    66102                beforeActualDecrypt = System.currentTimeMillis();
    67103                try {
    68                     BuildRequestRecord req = new BuildRequestRecord(ctx, privKey, rec);
     104                    rv = new BuildRequestRecord(ctx, privKey, rec);
     105                    afterActualDecrypt = System.currentTimeMillis();
     106
     107                    // i2pd bug
     108                    boolean isBad = SessionKey.INVALID_KEY.equals(rv.readReplyKey());
     109                    if (isBad) {
     110                        if (log.shouldLog(Log.WARN))
     111                            log.warn(msg.getUniqueId() + ": Bad reply key: " + rv);
     112                        ctx.statManager().addRateData("tunnel.buildRequestBadReplyKey", 1);
     113                        return null;
     114                    }
     115
     116                    // The spec says to feed the 32-byte AES-256 reply key into the Bloom filter.
     117                    // But we were using the first 32 bytes of the encrypted reply.
     118                    // Fixed in 0.9.24
     119                    boolean isDup = _filter.add(rv.getData(), BuildRequestRecord.OFF_REPLY_KEY, 32);
     120                    if (isDup) {
     121                        if (log.shouldLog(Log.WARN))
     122                            log.warn(msg.getUniqueId() + ": Dup record: " + rv);
     123                        ctx.statManager().addRateData("tunnel.buildRequestDup", 1);
     124                        return null;
     125                    }
     126
    69127                    if (log.shouldLog(Log.DEBUG))
    70                         log.debug(msg.getUniqueId() + ": A record matching our hash was found and decrypted");
    71                     rv = req;
     128                        log.debug(msg.getUniqueId() + ": Matching record: " + rv);
     129                    ourHop = i;
     130                    // TODO should we keep looking for a second match and fail if found?
     131                    break;
    72132                } catch (DataFormatException dfe) {
    73                     if (log.shouldLog(Log.DEBUG))
    74                         log.debug(msg.getUniqueId() + ": A record matching our hash was found, but could not be decrypted");
    75                     return null; // our hop is invalid?  b0rkage
     133                    if (log.shouldLog(Log.WARN))
     134                        log.warn(msg.getUniqueId() + ": Matching record decrypt failure", dfe);
     135                    // on the microscopic chance that there's another router
     136                    // out there with the same first 16 bytes, go around again
     137                    continue;
    76138                }
    77                 afterActualDecrypt = System.currentTimeMillis();
    78                 ourHop = i;
    79139            }
    80140        }
    81141        if (rv == null) {
    82142            // none of the records matched, b0rk
    83             if (log.shouldLog(Log.DEBUG))
    84                 log.debug(msg.getUniqueId() + ": No records matching our hash was found");
     143            if (log.shouldLog(Log.WARN))
     144                log.warn(msg.getUniqueId() + ": No matching record");
    85145            return null;
    86146        }
     
    89149        SessionKey replyKey = rv.readReplyKey();
    90150        byte iv[] = rv.readReplyIV();
    91         int ivOff = 0;
    92151        for (int i = 0; i < msg.getRecordCount(); i++) {
    93152            if (i != ourHop) {
    94153                EncryptedBuildRecord data = msg.getRecord(i);
    95                 if (log.shouldLog(Log.DEBUG))
    96                     log.debug("Encrypting record " + i + "/? with replyKey " + replyKey.toBase64() + "/" + Base64.encode(iv, ivOff, 16));
    97                 // corrupts SDS
    98                 ctx.aes().encrypt(data.getData(), 0, data.getData(), 0, replyKey,
    99                                   iv, ivOff, data.length());
     154                //if (log.shouldLog(Log.DEBUG))
     155                //    log.debug("Encrypting record " + i + "/? with replyKey " + replyKey.toBase64() + "/" + Base64.encode(iv));
     156                // encrypt in-place, corrupts SDS
     157                byte[] bytes = data.getData();
     158                ctx.aes().encrypt(bytes, 0, bytes, 0, replyKey, iv, 0, EncryptedBuildRecord.LENGTH);
    100159            }
    101160        }
     
    107166                         + " looping=" + (beforeEncrypt-beforeLoop)
    108167                         + " decrypt=" + (afterActualDecrypt-beforeActualDecrypt)
    109                          + " eq=" + totalEq
    110                          + " dup=" + totalDup
    111168                         + " encrypt=" + (afterEncrypt-beforeEncrypt));
    112169        }
  • router/java/src/net/i2p/router/tunnel/HopProcessor.java

    r3573928 rc8197b8  
    3232    static final int IV_LENGTH = 16;
    3333   
    34     /** @deprecated unused */
    35     public HopProcessor(I2PAppContext ctx, HopConfig config) {
    36         this(ctx, config, createValidator());
    37     }
    3834
    3935    public HopProcessor(I2PAppContext ctx, HopConfig config, IVValidator validator) {
     
    4238        _config = config;
    4339        _validator = validator;
    44     }
    45    
    46     /** @deprecated unused */
    47     protected static IVValidator createValidator() {
    48         // yeah, we'll use an O(1) validator later (e.g. bloom filter)
    49         return new HashSetIVValidator();
    5040    }
    5141   
  • router/java/src/net/i2p/router/tunnel/TunnelDispatcher.java

    r3573928 rc8197b8  
    205205        // following is for BuildMessageProcessor
    206206        ctx.statManager().createRateStat("tunnel.buildRequestDup", "How frequently we get dup build request messages", "Tunnels", new long[] { 60*60*1000 });
     207        ctx.statManager().createRateStat("tunnel.buildRequestBadReplyKey", "Build requests with bad reply keys", "Tunnels", new long[] { 60*60*1000 });
    207208        // following are for FragmentHandler
    208209        ctx.statManager().createRateStat("tunnel.smallFragments", "How many pad bytes are in small fragments?",
     
    604605                           + "/" + msg.getMessage().getUniqueId()
    605606                           + " messageType: " + msg.getMessage().getClass().getSimpleName()
    606                            + " existing = " + _inboundGateways.size(), new Exception("source"));
     607                           + " existing = " + _inboundGateways.size());
    607608        }
    608609       
  • router/java/src/net/i2p/router/tunnel/pool/BuildHandler.java

    r3573928 rc8197b8  
    4848 *
    4949 * Note that 10 minute tunnel expiration is hardcoded in here.
     50 *
     51 * There is only one of these objects but there may be multiple
     52 * threads running it. Instantiated and started by TunnelPoolManager.
     53 *
    5054 */
    5155class BuildHandler implements Runnable {
     
    123127        _context.statManager().createRequiredRateStat("tunnel.dropReqThrottle", "Drop per-hop limit", "Tunnels", new long[] { 60*60*1000 });
    124128        _context.statManager().createRequiredRateStat("tunnel.dropLookupThrottle", "Drop next hop lookup", "Tunnels", new long[] { 60*60*1000 });
     129        _context.statManager().createRateStat("tunnel.dropDecryptFail", "Can't find our slot", "Tunnels", new long[] { 60*60*1000 });
    125130
    126131        _context.statManager().createRequiredRateStat("tunnel.rejectOverloaded", "Delay to process rejected request (ms)", "Tunnels", new long[] { 60*1000, 10*60*1000 });
     
    460465        // with the enclosed reply key
    461466        long beforeDecrypt = System.currentTimeMillis();
    462         BuildRequestRecord req = _processor.decrypt(_context, state.msg, _context.routerHash(), _context.keyManager().getPrivateKey());
     467        BuildRequestRecord req = _processor.decrypt(state.msg, _context.routerHash(), _context.keyManager().getPrivateKey());
    463468        long decryptTime = System.currentTimeMillis() - beforeDecrypt;
    464469        _context.statManager().addRateData("tunnel.decryptRequestTime", decryptTime);
     
    467472        if (req == null) {
    468473            // no records matched, or the decryption failed.  bah
    469             if (_log.shouldLog(Log.WARN))
    470                 _log.warn("The request " + state.msg.getUniqueId() + " could not be decrypted");
     474            if (_log.shouldLog(Log.WARN)) {
     475                Hash from = state.fromHash;
     476                if (from == null && state.from != null)
     477                    from = state.from.calculateHash();
     478                _log.warn("The request " + state.msg.getUniqueId() + " could not be decrypted from: " + from);
     479            }
     480            _context.statManager().addRateData("tunnel.dropDecryptFail", 1);
    471481            return -1;
    472482        }
     
    9941004                        if (fh != null && _requestThrottler.shouldThrottle(fh)) {
    9951005                            if (_log.shouldLog(Log.WARN))
    996                                 _log.warn("Dropping tunnel request (from throttle), previous hop: " + from);
     1006                                _log.warn("Dropping tunnel request (from throttle), previous hop: " + fh);
    9971007                            _context.statManager().addRateData("tunnel.dropReqThrottle", 1);
    9981008                            accept = false;
  • router/java/src/net/i2p/router/util/DecayingBloomFilter.java

    r3573928 rc8197b8  
    6262        _longToEntryMask = 0;
    6363        context.addShutdownTask(new Shutdown());
    64         _decayEvent = new DecayEvent();
    6564        _keepDecaying = true;
    66         _decayEvent.schedule(_durationMs);
     65        if (_durationMs == 60*60*1000) {
     66            // special mode for BuildMessageProcessor
     67            _decayEvent = new DecayHourlyEvent();
     68        } else {
     69            _decayEvent = new DecayEvent();
     70            _decayEvent.schedule(_durationMs);
     71        }
    6772    }
    6873
    6974    /**
    7075     * Create a bloom filter that will decay its entries over time. 
     76     * Uses default m of 23, memory usage is 2 MB.
    7177     *
    7278     * @param durationMs entries last for at least this long, but no more than twice this long
     
    7985    }
    8086
    81     /** @param name just for logging / debugging / stats */
     87    /**
     88     * Uses default m of 23, memory usage is 2 MB.
     89     * @param name just for logging / debugging / stats
     90     */
    8291    public DecayingBloomFilter(I2PAppContext context, int durationMs, int entryBytes, String name) {
    8392        // this is instantiated in four different places, they may have different
     
    8897
    8998    /**
     99     * Memory usage is 2 * (2**m) bits or 2**(m-2) bytes.
     100     *
    90101     * @param m filter size exponent, max is 29
    91102     */
     
    124135            _longToEntryMask = 0;
    125136        }
    126         _decayEvent = new DecayEvent();
    127137        _keepDecaying = true;
    128         _decayEvent.schedule(_durationMs);
     138        if (_durationMs == 60*60*1000) {
     139            // special mode for BuildMessageProcessor
     140            _decayEvent = new DecayHourlyEvent();
     141        } else {
     142            _decayEvent = new DecayEvent();
     143            _decayEvent.schedule(_durationMs);
     144        }
    129145        if (_log.shouldLog(Log.WARN))
    130146           _log.warn("New DBF " + name + " m = " + m + " k = " + k + " entryBytes = " + entryBytes +
     
    319335   
    320336    private class DecayEvent extends SimpleTimer2.TimedEvent {
     337        /**
     338         *  Caller MUST schedule.
     339         */
    321340        DecayEvent() {
    322341            super(_context.simpleTimer2());
    323342        }
    324        
     343
    325344        public void timeReached() {
    326345            if (_keepDecaying) {
     
    328347                schedule(_durationMs);
    329348            }
     349        }
     350    }
     351   
     352    /**
     353     *  Decays at 5 minutes after the top of the hour.
     354     *  This ignores leap seconds.
     355     *  @since 0.9.24
     356     */
     357    private class DecayHourlyEvent extends SimpleTimer2.TimedEvent {
     358        private static final long HOUR = 60 * 60 * 1000L;
     359        private static final long LAG = 5 * 60 * 1000L;
     360        private volatile long _currentHour;
     361
     362        /**
     363         *  Schedules itself. Caller MUST NOT schedule.
     364         */
     365        DecayHourlyEvent() {
     366            super(_context.simpleTimer2());
     367            schedule(getTimeTillNextHour());
     368        }
     369
     370        public void timeReached() {
     371            if (_keepDecaying) {
     372                long now = _context.clock().now();
     373                long currentHour = now / HOUR;
     374                // handle possible clock adjustments
     375                if (_currentHour != currentHour) {
     376                    decay();
     377                    _currentHour = currentHour;
     378                }
     379                long next = ((1 + currentHour) * HOUR) + LAG;
     380                schedule(Math.max(5000, next - now));
     381            }
     382        }
     383
     384        /** side effect: sets _currentHour */
     385        private long getTimeTillNextHour() {
     386            long now = _context.clock().now();
     387            long currentHour = now / HOUR;
     388            _currentHour = currentHour;
     389            long next = ((1 + currentHour) * HOUR) + LAG;
     390            return Math.max(5000, next - now);
    330391        }
    331392    }
Note: See TracChangeset for help on using the changeset viewer.