From 59373f9bdf513f09a20d71eca424d34dd9018989 Mon Sep 17 00:00:00 2001 From: zzz Date: Wed, 28 Jan 2015 15:04:59 +0000 Subject: [PATCH] UPnP: - Rescan for devices periodically and when reachability changes (tickets #661, #959) - Don't put "I2P" in registered protocol name - Add uptime to UPnP info - HTML escaping - Remove static log on Android - Javadocs and cleanups --- history.txt | 15 ++++ .../src/net/i2p/router/RouterVersion.java | 2 +- .../router/transport/TransportManager.java | 9 +- .../src/net/i2p/router/transport/UPnP.java | 84 ++++++++++++------ .../net/i2p/router/transport/UPnPManager.java | 85 ++++++++++++++++++- .../java/src/org/cybergarage/util/Debug.java | 4 + 6 files changed, 170 insertions(+), 29 deletions(-) diff --git a/history.txt b/history.txt index 59f95faa2..c1f411d80 100644 --- a/history.txt +++ b/history.txt @@ -1,3 +1,18 @@ +2015-01-28 zzz + * UPnP: + - Rescan for devices periodically and when reachability changes (tickets #661, #959) + - Don't put "I2P" in registered protocol name + - Add uptime to UPnP info + - HTML escaping + - Remove static log on Android + +2015-01-11 zzz + * i2psnark: Skip incompatible welterde tracker if we are ECDSA + * I2PTunnel: Add option for multihoming optimization + +2015-01-10 zzz + * NetDB: Stubs for bandwidth estimation during reseed (ticket #935) + 2015-01-09 zzz * NetDB: Publish RI faster when costs change (ticket #1437) diff --git a/router/java/src/net/i2p/router/RouterVersion.java b/router/java/src/net/i2p/router/RouterVersion.java index 7ca1a3ec2..5a58b19bc 100644 --- a/router/java/src/net/i2p/router/RouterVersion.java +++ b/router/java/src/net/i2p/router/RouterVersion.java @@ -18,7 +18,7 @@ public class RouterVersion { /** deprecated */ public final static String ID = "Monotone"; public final static String VERSION = CoreVersion.VERSION; - public final static long BUILD = 10; + public final static long BUILD = 11; /** for example "-test" */ public final static String EXTRA = ""; diff --git a/router/java/src/net/i2p/router/transport/TransportManager.java b/router/java/src/net/i2p/router/transport/TransportManager.java index 5062cc14b..952de0d0a 100644 --- a/router/java/src/net/i2p/router/transport/TransportManager.java +++ b/router/java/src/net/i2p/router/transport/TransportManager.java @@ -593,8 +593,11 @@ public class TransportManager implements TransportEventListener { } public void transportAddressChanged() { - if (_upnpManager != null) + if (_upnpManager != null) { + _upnpManager.rescan(); + // should really delay the following by 5 seconds? _upnpManager.update(getPorts()); + } } public List getMostRecentErrorMessages() { @@ -605,6 +608,10 @@ public class TransportManager implements TransportEventListener { return rv; } + /** + * Warning - blocking, very slow, queries the active UPnP router, + * will take many seconds if it has vanished. + */ public void renderStatusHTML(Writer out, String urlBase, int sortFlags) throws IOException { TreeMap transports = new TreeMap(); for (Transport t : _transports.values()) { diff --git a/router/java/src/net/i2p/router/transport/UPnP.java b/router/java/src/net/i2p/router/transport/UPnP.java index 582f92272..9478909f1 100644 --- a/router/java/src/net/i2p/router/transport/UPnP.java +++ b/router/java/src/net/i2p/router/transport/UPnP.java @@ -111,6 +111,7 @@ class UPnP extends ControlPoint implements DeviceChangeListener, EventListener { public synchronized boolean runPlugin() { synchronized(lock) { portsToForward.clear(); + portsForwarded.clear(); } return super.start(); } @@ -190,6 +191,8 @@ class UPnP extends ControlPoint implements DeviceChangeListener, EventListener { String name = dev.getFriendlyName(); if (name == null) name = "???"; + boolean isIGD = ROUTER_DEVICE.equals(dev.getDeviceType()) && dev.isRootDevice(); + name += isIGD ? " IGD" : (" " + dev.getDeviceType()); synchronized (lock) { if(isDisabled) { if (_log.shouldLog(Log.WARN)) @@ -200,7 +203,7 @@ class UPnP extends ControlPoint implements DeviceChangeListener, EventListener { } if(!ROUTER_DEVICE.equals(dev.getDeviceType()) || !dev.isRootDevice()) { if (_log.shouldLog(Log.WARN)) - _log.warn("UP&P non-IGD device found, ignoring " + name); + _log.warn("UP&P non-IGD device found, ignoring " + name + ' ' + dev.getDeviceType()); synchronized (lock) { _otherUDNs.put(udn, name); } @@ -292,8 +295,8 @@ class UPnP extends ControlPoint implements DeviceChangeListener, EventListener { _service = current2.getService(WAN_PPP_CONNECTION); if(_service == null) { - if (_log.shouldLog(Log.WARN)) - _log.warn(_router.getFriendlyName()+ " doesn't seems to be using PPP; we won't be able to extract bandwidth-related informations out of it."); + if (_log.shouldLog(Log.INFO)) + _log.info(_router.getFriendlyName()+ " doesn't seems to be using PPP; we won't be able to extract bandwidth-related informations out of it."); _service = current2.getService(WAN_IP_CONNECTION); if(_service == null) _log.error(_router.getFriendlyName()+ " doesn't export WAN_IP_CONNECTION either: we won't be able to use it!"); @@ -312,7 +315,8 @@ class UPnP extends ControlPoint implements DeviceChangeListener, EventListener { int nbOfTries = 0; boolean isPortForwarded = false; while ((!_serviceLacksAPM) && nbOfTries++ < 5) { - isPortForwarded = addMapping(protocol, port, "I2P " + description, fp); + //isPortForwarded = addMapping(protocol, port, "I2P " + description, fp); + isPortForwarded = addMapping(protocol, port, description, fp); if(isPortForwarded || _serviceLacksAPM) break; try { @@ -342,11 +346,11 @@ class UPnP extends ControlPoint implements DeviceChangeListener, EventListener { if (_log.shouldLog(Log.WARN)) _log.warn("UP&P device removed : " + dev.getFriendlyName() + " UDN: " + udn); synchronized (lock) { - if(_router == null) return; if (udn != null) _otherUDNs.remove(udn); else _otherUDNs.remove("???"); + if (_router == null) return; // I2P this wasn't working //if(_router.equals(dev)) { if(ROUTER_DEVICE.equals(dev.getDeviceType()) && @@ -355,9 +359,11 @@ class UPnP extends ControlPoint implements DeviceChangeListener, EventListener { stringEquals(_router.getUDN(), udn)) { if (_log.shouldLog(Log.WARN)) _log.warn("UP&P IGD device removed : " + dev.getFriendlyName()); + // TODO promote an IGD from _otherUDNs ?? _router = null; _service = null; _serviceLacksAPM = false; + portsForwarded.clear(); } } } @@ -381,7 +387,7 @@ class UPnP extends ControlPoint implements DeviceChangeListener, EventListener { /** * @return whether we are behind an UPnP-enabled NAT/router */ - public boolean isNATPresent() { + private boolean isNATPresent() { return _router != null && _service != null; } @@ -389,7 +395,7 @@ class UPnP extends ControlPoint implements DeviceChangeListener, EventListener { * @return the external address the NAT thinks we have. Blocking. * null if we can't find it. */ - public String getNATAddress() { + private String getNATAddress() { if(!isNATPresent()) return null; @@ -399,7 +405,7 @@ class UPnP extends ControlPoint implements DeviceChangeListener, EventListener { String rv = (getIP.getOutputArgumentList().getArgument("NewExternalIPAddress")).getValue(); // I2P some devices return 0.0.0.0 when not connected - if ("0.0.0.0".equals(rv)) + if ("0.0.0.0".equals(rv) || rv == null || rv.length() <= 0) return null; return rv; } @@ -407,7 +413,7 @@ class UPnP extends ControlPoint implements DeviceChangeListener, EventListener { /** * @return the reported upstream bit rate in bits per second. -1 if it's not available. Blocking. */ - public int getUpstreamMaxBitRate() { + private int getUpstreamMaxBitRate() { if(!isNATPresent() || thinksWeAreDoubleNatted) return -1; @@ -425,7 +431,7 @@ class UPnP extends ControlPoint implements DeviceChangeListener, EventListener { /** * @return the reported downstream bit rate in bits per second. -1 if it's not available. Blocking. */ - public int getDownstreamMaxBitRate() { + private int getDownstreamMaxBitRate() { if(!isNATPresent() || thinksWeAreDoubleNatted) return -1; @@ -454,7 +460,9 @@ class UPnP extends ControlPoint implements DeviceChangeListener, EventListener { sb.append("
    "); for(int i=0; i" + current.getName() + " : \"" + current.getValue() + "\""); + sb.append("
  • ").append(DataHelper.escapeHTML(current.getName())) + .append(" : \"").append(DataHelper.escapeHTML(current.getValue())) + .append("\"
    • "); } sb.append("
"); } @@ -466,7 +474,8 @@ class UPnP extends ControlPoint implements DeviceChangeListener, EventListener { for(int i=0; iargument : ").append(argument.getName()).append(""); + sb.append("
  • argument : ").append(DataHelper.escapeHTML(argument.getName())) + .append("
    • "); } sb.append(""); } @@ -478,7 +487,7 @@ class UPnP extends ControlPoint implements DeviceChangeListener, EventListener { for(int i=0; i").append(action.getName()); + sb.append("
  • ").append(DataHelper.escapeHTML(action.getName())); listActionsArguments(action, sb); sb.append("
    • "); } @@ -495,6 +504,7 @@ class UPnP extends ControlPoint implements DeviceChangeListener, EventListener { private Service _lastService; private ArgumentList _lastArgumentList; private final Object toStringLock = new Object(); + private String toString(String action, String arg, Service serv) { synchronized(toStringLock) { if ((!action.equals(_lastAction)) || @@ -509,7 +519,8 @@ class UPnP extends ControlPoint implements DeviceChangeListener, EventListener { _lastService = serv; _lastArgumentList = getIP.getOutputArgumentList(); } - return _lastArgumentList.getArgument(arg).getValue(); + String rv = _lastArgumentList.getArgument(arg).getValue(); + return DataHelper.escapeHTML(rv); } } @@ -523,6 +534,8 @@ class UPnP extends ControlPoint implements DeviceChangeListener, EventListener { Service serv = sl.getService(i); if(serv == null) continue; sb.append("
  • ").append(_("Service")).append(": "); + // NOTE: Group all toString() of common actions together + // to avoid excess fetches, since toString() caches. if("urn:schemas-upnp-org:service:WANCommonInterfaceConfig:1".equals(serv.getServiceType())){ sb.append(_("WAN Common Interface Configuration")); sb.append("
    • ").append(_("Status")).append(": ") @@ -538,6 +551,15 @@ class UPnP extends ControlPoint implements DeviceChangeListener, EventListener { sb.append(_("WAN PPP Connection")); sb.append("
      • ").append(_("Status")).append(": ") .append(toString("GetStatusInfo", "NewConnectionStatus", serv)); + String up = toString("GetStatusInfo", "NewUptime", serv); + if (up != null) { + try { + long uptime = Long.parseLong(up); + uptime *= 1000; + sb.append("
      • ").append(_("Uptime")).append(": ") + .append(DataHelper.formatDuration2(uptime)); + } catch (NumberFormatException nfe) {} + } sb.append("
      • ").append(_("Type")).append(": ") .append(toString("GetConnectionTypeInfo", "NewConnectionType", serv)); sb.append("
      • ").append(_("Upstream")).append(": ") @@ -554,8 +576,19 @@ class UPnP extends ControlPoint implements DeviceChangeListener, EventListener { .append("
        • "); }else if(WAN_IP_CONNECTION.equals(serv.getServiceType())){ sb.append(_("WAN IP Connection")); - sb.append("
        • ").append(_("Status")).append(": " + toString("GetStatusInfo", "NewConnectionStatus", serv)); - sb.append("
        • ").append(_("Type")).append(": " + toString("GetConnectionTypeInfo", "NewConnectionType", serv)); + sb.append("
          • ").append(_("Status")).append(": ") + .append(toString("GetStatusInfo", "NewConnectionStatus", serv)); + String up = toString("GetStatusInfo", "NewUptime", serv); + if (up != null) { + try { + long uptime = Long.parseLong(up); + uptime *= 1000; + sb.append("
          • ").append(_("Uptime")).append(": ") + .append(DataHelper.formatDuration2(uptime)); + } catch (NumberFormatException nfe) {} + } + sb.append("
          • ").append(_("Type")).append(": ") + .append(toString("GetConnectionTypeInfo", "NewConnectionType", serv)); sb.append("
          • ").append(_("External IP")).append(": ") .append(toString("GetExternalIPAddress", "NewExternalIPAddress", serv)) .append("
            • "); @@ -564,8 +597,9 @@ class UPnP extends ControlPoint implements DeviceChangeListener, EventListener { sb.append("
            • ").append(_("Status")).append(": ") .append(toString("GetEthernetLinkStatus", "NewEthernetLinkStatus", serv)) .append("
              • "); - }else - sb.append("~~~~~~~ "+serv.getServiceType() + "
                "); + } else { + sb.append(DataHelper.escapeHTML(serv.getServiceType())).append("
                  "); + } if (_context.getBooleanProperty(PROP_ADVANCED)) { sb.append("
                • Actions"); listActions(serv, sb); @@ -583,7 +617,7 @@ class UPnP extends ControlPoint implements DeviceChangeListener, EventListener { sb.append("

                  ").append(_("Found Device")).append(": "); else sb.append("

                • ").append(_("Subdevice")).append(": "); - sb.append(dev.getFriendlyName()); + sb.append(DataHelper.escapeHTML(dev.getFriendlyName())); if (prefix == null) sb.append("

                  "); listSubServices(dev, sb); @@ -612,8 +646,8 @@ class UPnP extends ControlPoint implements DeviceChangeListener, EventListener { for (Map.Entry e : _otherUDNs.entrySet()) { String udn = e.getKey(); String name = e.getValue(); - sb.append("
                • ").append(name) - .append("
                  UDN: ").append(udn) + sb.append("
                • ").append(DataHelper.escapeHTML(name)); + sb.append("
                  UDN: ").append(DataHelper.escapeHTML(udn)) .append("
                  • "); } sb.append("
                "); @@ -632,7 +666,7 @@ class UPnP extends ControlPoint implements DeviceChangeListener, EventListener { String addr = getNATAddress(); sb.append("

                "); if (addr != null) - sb.append(_("The current external IP address reported by UPnP is {0}", addr)); + sb.append(_("The current external IP address reported by UPnP is {0}", DataHelper.escapeHTML(addr))); else sb.append(_("The current external IP address is not available.")); int downstreamMaxBitRate = getDownstreamMaxBitRate(); @@ -839,7 +873,7 @@ class UPnP extends ControlPoint implements DeviceChangeListener, EventListener { Set portsToDumpNow = null; Set portsToForwardNow = null; if (_log.shouldLog(Log.INFO)) - _log.info("UP&P Forwarding "+ports.size()+" ports..."); + _log.info("UP&P Forwarding "+ports.size()+" ports...", new Exception()); synchronized(lock) { if(forwardCallback != null && forwardCallback != cb && cb != null) { _log.error("ForwardPortCallback changed from "+forwardCallback+" to "+cb+" - using new value, but this is very strange!"); @@ -1008,10 +1042,12 @@ class UPnP extends ControlPoint implements DeviceChangeListener, EventListener { System.out.println("Found " + list.size() + " devices!"); StringBuilder sb = new StringBuilder(); Iterator it = list.iterator(); + int i = 0; while(it.hasNext()) { Device device = it.next(); upnp.listSubDev(device.toString(), device, sb); - System.out.println("Here is the listing for " + device.toString() + " :"); + System.out.println("Here is the listing for device " + (++i) + + ' ' + device.getFriendlyName() + " :"); System.out.println(sb.toString()); sb.setLength(0); } diff --git a/router/java/src/net/i2p/router/transport/UPnPManager.java b/router/java/src/net/i2p/router/transport/UPnPManager.java index d7e5544e0..6a970ee68 100644 --- a/router/java/src/net/i2p/router/transport/UPnPManager.java +++ b/router/java/src/net/i2p/router/transport/UPnPManager.java @@ -13,6 +13,7 @@ import net.i2p.router.RouterContext; import static net.i2p.router.transport.Transport.AddressSource.SOURCE_UPNP; import net.i2p.util.Addresses; import net.i2p.util.Log; +import net.i2p.util.SimpleTimer2; import net.i2p.util.Translate; import org.cybergarage.util.Debug; @@ -34,8 +35,12 @@ class UPnPManager { private final UPnP _upnp; private final UPnPCallback _upnpCallback; private volatile boolean _isRunning; + private volatile boolean _shouldBeRunning; + private volatile long _lastRescan; + private volatile boolean _errorLogged; private InetAddress _detectedAddress; private final TransportManager _manager; + private final SimpleTimer2.TimedEvent _rescanner; /** * This is the TCP HTTP Event listener * We move these so we don't conflict with other users of the same upnp library @@ -46,6 +51,12 @@ class UPnPManager { /** this is the UDP SSDP Search reply listener */ private static final String PROP_SSDP_PORT = "i2np.upnp.SSDPPort"; private static final int DEFAULT_SSDP_PORT = 7653; + private static final long RESCAN_MIN_DELAY = 60*1000; + private static final long RESCAN_SHORT_DELAY = 2*60*1000; + // minimum UPnP announce interval is 30 minutes. Let's be faster + // 30 minutes is also the default "lease time" in cybergarage. + // It expires after 31 minutes. + private static final long RESCAN_LONG_DELAY = 14*60*1000; public UPnPManager(RouterContext context, TransportManager manager) { _context = context; @@ -60,6 +71,7 @@ class UPnPManager { _upnp.setHTTPPort(_context.getProperty(PROP_HTTP_PORT, DEFAULT_HTTP_PORT)); _upnp.setSSDPPort(_context.getProperty(PROP_SSDP_PORT, DEFAULT_SSDP_PORT)); _upnpCallback = new UPnPCallback(); + _rescanner = new Rescanner(); } /** @@ -68,6 +80,7 @@ class UPnPManager { public synchronized void start() { if (_log.shouldLog(Log.DEBUG)) _log.debug("UPnP Start"); + _shouldBeRunning = true; if (!_isRunning) { long b = _context.clock().now(); try { @@ -76,10 +89,18 @@ class UPnPManager { _log.info("UPnP runPlugin took " + (_context.clock().now() - b)); } catch (Exception e) { // NPE in UPnP (ticket #728), can't let it bring us down - _log.error("UPnP error, please report", e); + if (!_errorLogged) { + _log.error("UPnP error, please report", e); + _errorLogged = true; + } } } - if (!_isRunning) { + if (_isRunning) { + _rescanner.schedule(RESCAN_LONG_DELAY); + if (_log.shouldLog(Log.DEBUG)) + _log.debug("UPnP Start Done"); + } else { + _rescanner.schedule(RESCAN_SHORT_DELAY); // Do we have a non-loopback, non-broadcast address? // If not, that's why it failed (HTTPServer won't start) if (!Addresses.isConnected()) @@ -90,15 +111,69 @@ class UPnPManager { } /** - * Blocking, may take a while + * Blocking, may take a while, up to 20 seconds */ public synchronized void stop() { if (_log.shouldLog(Log.DEBUG)) _log.debug("UPnP Stop"); + _shouldBeRunning = false; + _rescanner.cancel(); if (_isRunning) _upnp.terminate(); _isRunning = false; _detectedAddress = null; + if (_log.shouldLog(Log.DEBUG)) + _log.debug("UPnP Stop Done"); + } + + /** + * Call when IP or network connectivity might have changed. + * Starts UPnP if previous start failed, else starts a search. + * Must have called start() first, and not called stop(). + * + * Should be fast. This only starts the search, the responses + * will come in over the MX time (3 seconds). + * + * @since 0.9.18 + */ + public synchronized void rescan() { + if (!_shouldBeRunning) + return; + long now = System.currentTimeMillis(); + if (_lastRescan + RESCAN_MIN_DELAY > now) + return; + _lastRescan = now; + if (_log.shouldLog(Log.DEBUG)) + _log.debug("UPnP Rescan Start"); + if (_isRunning) { + // TODO default search MX (jitter) is 3 seconds... reduce? + // See also: + // Adaptive Jitter Control for UPnP M-Search + // Kevin Mills and Christopher Dabrowski + _upnp.search(); + } else { + start(); + } + } + + /** + * Initiate a UPnP search + * + * @since 0.9.18 + */ + private class Rescanner extends SimpleTimer2.TimedEvent { + + /** caller must schedule() */ + public Rescanner() { + super(_context.simpleTimer2()); + } + + public void timeReached() { + if (_shouldBeRunning) { + rescan(); + reschedule(_isRunning ? RESCAN_LONG_DELAY : RESCAN_SHORT_DELAY); + } + } } /** @@ -192,6 +267,10 @@ class UPnPManager { } } + /** + * Warning - blocking, very slow, queries the active router, + * will take many seconds if it has vanished. + */ public String renderStatusHTML() { if (!_isRunning) return "

                " + _("UPnP is not enabled") + "

                \n"; diff --git a/router/java/src/org/cybergarage/util/Debug.java b/router/java/src/org/cybergarage/util/Debug.java index c6415591e..c3ca4d088 100644 --- a/router/java/src/org/cybergarage/util/Debug.java +++ b/router/java/src/org/cybergarage/util/Debug.java @@ -17,6 +17,7 @@ package org.cybergarage.util; import net.i2p.I2PAppContext; import net.i2p.util.Log; +import net.i2p.util.SystemVersion; public final class Debug { @@ -24,6 +25,9 @@ public final class Debug /** I2P this is all static so have the UPnPManager call this */ public static void initialize(I2PAppContext ctx) { + // don't keep static ref on android, just skip it + if (SystemVersion.isAndroid()) + return; _log = ctx.logManager().getLog(Debug.class); // org.cybergarage.util.Debug=DEBUG at startup enabled = _log.shouldLog(Log.DEBUG);