From 05a0a20197cc9e4e176a16820ab672f20815fce4 Mon Sep 17 00:00:00 2001 From: Joseph Henry Date: Wed, 8 Dec 2021 14:32:58 -0800 Subject: [PATCH 1/9] Fix multipath flow reallocation. Prevent allocation to dead paths --- node/Bond.cpp | 13 +++++-------- 1 file changed, 5 insertions(+), 8 deletions(-) diff --git a/node/Bond.cpp b/node/Bond.cpp index f294eb431..62adcf5fd 100644 --- a/node/Bond.cpp +++ b/node/Bond.cpp @@ -894,13 +894,13 @@ void Bond::curateBond(int64_t now, bool rebuildBond) if (! currEligibility) { _paths[i].adjustRefractoryPeriod(now, _defaultPathRefractoryPeriod, ! currEligibility); if (_paths[i].bonded) { - _paths[i].bonded = false; if (_allowFlowHashing) { _paths[i].p->address().toString(pathStr); log("link %s/%s was bonded, flow reallocation will occur soon", getLink(_paths[i].p)->ifname().c_str(), pathStr); rebuildBond = true; _paths[i].shouldReallocateFlows = _paths[i].bonded; } + _paths[i].bonded = false; } } } @@ -979,7 +979,7 @@ void Bond::curateBond(int64_t now, bool rebuildBond) if (ipvPref == 0) { for (int j = 0; j < it->second.size(); j++) { int idx = it->second.at(j); - if (! _paths[idx].p || ! _paths[idx].allowed()) { + if (! _paths[idx].p || ! _paths[idx].eligible || ! _paths[idx].allowed()) { continue; } addPathToBond(idx, updatedBondedPathCount); @@ -992,7 +992,7 @@ void Bond::curateBond(int64_t now, bool rebuildBond) if (ipvPref == 4 || ipvPref == 6) { for (int j = 0; j < it->second.size(); j++) { int idx = it->second.at(j); - if (! _paths[idx].p) { + if (! _paths[idx].p || ! _paths[idx].eligible) { continue; } if (! _paths[idx].allowed()) { @@ -1000,9 +1000,6 @@ void Bond::curateBond(int64_t now, bool rebuildBond) log("did not add %s/%s (user addr preference %d)", link->ifname().c_str(), pathStr, ipvPref); continue; } - if (! _paths[idx].eligible) { - continue; - } addPathToBond(idx, updatedBondedPathCount); ++updatedBondedPathCount; _paths[idx].p->address().toString(pathStr); @@ -1016,10 +1013,10 @@ void Bond::curateBond(int64_t now, bool rebuildBond) // Search for preferred paths for (int j = 0; j < it->second.size(); j++) { int idx = it->second.at(j); - if (! _paths[idx].p || ! _paths[idx].eligible) { + if (! _paths[idx].p || ! _paths[idx].eligible || ! _paths[idx].allowed()) { continue; } - if (_paths[idx].preferred() && _paths[idx].allowed()) { + if (_paths[idx].preferred()) { addPathToBond(idx, updatedBondedPathCount); ++updatedBondedPathCount; _paths[idx].p->address().toString(pathStr); From 1f43a736b2fed63c501674afe214145acf4a5988 Mon Sep 17 00:00:00 2001 From: Joseph Henry Date: Thu, 9 Dec 2021 13:43:52 -0800 Subject: [PATCH 2/9] Fix active-backup path selection bug --- node/Bond.cpp | 11 +++++++---- node/Bond.hpp | 2 +- 2 files changed, 8 insertions(+), 5 deletions(-) diff --git a/node/Bond.cpp b/node/Bond.cpp index 62adcf5fd..05bd7a842 100644 --- a/node/Bond.cpp +++ b/node/Bond.cpp @@ -661,7 +661,7 @@ void Bond::processIncomingPathNegotiationRequest(uint64_t now, SharedPtr& if (remoteUtility > _localUtility) { _paths[pathIdx].p->address().toString(pathStr); log("peer suggests alternate link %s/%s, remote utility (%d) greater than local utility (%d), switching to suggested link\n", link->ifname().c_str(), pathStr, remoteUtility, _localUtility); - negotiatedPathIdx = pathIdx; + _negotiatedPathIdx = pathIdx; } if (remoteUtility < _localUtility) { log("peer suggests alternate link %s/%s, remote utility (%d) less than local utility (%d), not switching\n", link->ifname().c_str(), pathStr, remoteUtility, _localUtility); @@ -670,7 +670,7 @@ void Bond::processIncomingPathNegotiationRequest(uint64_t now, SharedPtr& log("peer suggests alternate link %s/%s, remote utility (%d) equal to local utility (%d)\n", link->ifname().c_str(), pathStr, remoteUtility, _localUtility); if (_peer->_id.address().toInt() > RR->node->identity().address().toInt()) { log("agree with peer to use alternate link %s/%s\n", link->ifname().c_str(), pathStr); - negotiatedPathIdx = pathIdx; + _negotiatedPathIdx = pathIdx; } else { log("ignore petition from peer to use alternate link %s/%s\n", link->ifname().c_str(), pathStr); @@ -730,7 +730,7 @@ void Bond::pathNegotiationCheck(void* tPtr, int64_t now) if (_localUtility == 0) { // There's no loss to us, just switch without sending a another request // fprintf(stderr, "BT: (sync) giving up, switching to remote peer's path.\n"); - negotiatedPathIdx = maxInPathIdx; + _negotiatedPathIdx = maxInPathIdx; } } } @@ -1478,13 +1478,15 @@ void Bond::processActiveBackupTasks(void* tPtr, int64_t now) // If using "optimize" primary re-select mode, ignore user link designations failoverScoreHandicap = ZT_BOND_FAILOVER_HANDICAP_PRIMARY; } - if (_paths[i].p.ptr() == _paths[negotiatedPathIdx].p.ptr()) { + /* + if (_paths[i].p.ptr() == _paths[_negotiatedPathIdx].p.ptr()) { _paths[i].negotiated = true; failoverScoreHandicap = ZT_BOND_FAILOVER_HANDICAP_NEGOTIATED; } else { _paths[i].negotiated = false; } + */ _paths[i].failoverScore = _paths[i].allocation + failoverScoreHandicap; if (_paths[i].p.ptr() != _paths[_abPathIdx].p.ptr()) { bool bFoundPathInQueue = false; @@ -1622,6 +1624,7 @@ void Bond::setBondParameters(int policy, SharedPtr templateBond, bool useT _pathNegotiationCutoffCount = 0; _lastPathNegotiationReceived = 0; _localUtility = 0; + _negotiatedPathIdx = 0; // QOS Verb (and related checks) diff --git a/node/Bond.hpp b/node/Bond.hpp index 90c80d974..f9f85beed 100644 --- a/node/Bond.hpp +++ b/node/Bond.hpp @@ -1428,7 +1428,7 @@ class Bond { // path negotiation int16_t _localUtility; - int negotiatedPathIdx; + int _negotiatedPathIdx; uint8_t _numSentPathNegotiationRequests; bool _allowPathNegotiation; From e9375b50b0b7228f77dc8ef3d99d1021f89675ff Mon Sep 17 00:00:00 2001 From: Joseph Henry Date: Mon, 13 Dec 2021 11:54:23 -0800 Subject: [PATCH 3/9] Prevent path-amnesia --- include/ZeroTierOne.h | 2 +- node/Peer.cpp | 60 +++++++++++++++++++++++++++++++++++-------- 2 files changed, 51 insertions(+), 11 deletions(-) diff --git a/include/ZeroTierOne.h b/include/ZeroTierOne.h index 2bdea6474..ca435a71f 100644 --- a/include/ZeroTierOne.h +++ b/include/ZeroTierOne.h @@ -163,7 +163,7 @@ extern "C" { /** * Maximum number of direct network paths to a given peer */ -#define ZT_MAX_PEER_NETWORK_PATHS 16 +#define ZT_MAX_PEER_NETWORK_PATHS 64 /** * Maximum number of path configurations that can be set diff --git a/node/Peer.cpp b/node/Peer.cpp index a9dd8ce1e..ab4cb7c51 100644 --- a/node/Peer.cpp +++ b/node/Peer.cpp @@ -118,28 +118,68 @@ void Peer::received( } if ( (!havePath) && RR->node->shouldUsePathForZeroTierTraffic(tPtr,_id.address(),path->localSocket(),path->address()) ) { + + /** + * First, fill all free slots before attempting to replace a path + * - If the above fails, attempt to replace the path that has been dead the longest + * - If there are no free slots, and no dead paths (unlikely), then replace old path most similar to new path + * - If all of the above fails to yield a suitable replacement. Replace first path found to have lower `(quality / priority)` + */ + if (verb == Packet::VERB_OK) { Mutex::Lock _l(_paths_m); - unsigned int replacePath = ZT_MAX_PEER_NETWORK_PATHS; + uint64_t maxScore = 0; + uint64_t currScore; long replacePathQuality = 0; + bool foundFreeSlot = false; + for(unsigned int i=0;ialive(now)) || _paths[i].p->address().ipsEqual(path->address()) ) { - replacePath = i; - break; - } else { - const long q = _paths[i].p->quality(now) / _paths[i].priority; - if (q > replacePathQuality) { - replacePathQuality = q; - replacePath = i; + // Reward dead paths + if (!_paths[i].p->alive(now)) { + currScore = _paths[i].p->age(now) / 1000; + } + // Reward as similarity increases + if (_paths[i].p->address().ipsEqual(path->address())) { + currScore++; + if (_paths[i].p->address().port() == path->address().port()) { + currScore++; + if (_paths[i].p->localSocket() == path->localSocket()) { + currScore++; // max score (3) + } } } - } else { + // If best so far, mark for replacement + if (currScore > maxScore) { + maxScore = currScore; + replacePath = i; + } + } + else { + foundFreeSlot = true; replacePath = i; break; } } + if (!foundFreeSlot) { + if (maxScore > 3) { + // Do nothing. We found a dead path and have already marked it as a candidate + } + // If we couldn't find a replacement by matching, replacing a dead path, or taking a free slot, then replace by quality + else if (maxScore == 0) { + for(unsigned int i=0;iquality(now) / _paths[i].priority; + if (q > replacePathQuality) { + replacePathQuality = q; + replacePath = i; + } + } + } + } + } if (replacePath != ZT_MAX_PEER_NETWORK_PATHS) { RR->t->peerLearnedNewPath(tPtr, networkId, *this, path, packetId); From afdc91f21fabc2fedd81d7c0b0529669d963f50b Mon Sep 17 00:00:00 2001 From: Travis LaDuke Date: Fri, 5 Nov 2021 08:02:10 -0700 Subject: [PATCH 4/9] Convince macOS to do ipv6 dns lookups Puts a value into System Config, similar to how DNS push works. closes #1466 https://apple.stackexchange.com/questions/309430/ipv6-dns-resolution-on-macos-high-sierra --- osdep/MacDNSHelper.hpp | 3 + osdep/MacDNSHelper.mm | 133 ++++++++++++++++++++++++++++++++++++++- osdep/MacEthernetTap.cpp | 1 + service/OneService.cpp | 5 ++ 4 files changed, 141 insertions(+), 1 deletion(-) diff --git a/osdep/MacDNSHelper.hpp b/osdep/MacDNSHelper.hpp index 7a2902fa5..2fa283621 100644 --- a/osdep/MacDNSHelper.hpp +++ b/osdep/MacDNSHelper.hpp @@ -3,6 +3,7 @@ #include #include "../node/InetAddress.hpp" +#include "../node/MAC.hpp" namespace ZeroTier { @@ -11,6 +12,8 @@ class MacDNSHelper public: static void setDNS(uint64_t nwid, const char *domain, const std::vector &servers); static void removeDNS(uint64_t nwid); + static bool addIps(uint64_t nwid, const MAC mac, const char *dev, const std::vector &addrs); + static bool removeIps(uint64_t nwid); }; } diff --git a/osdep/MacDNSHelper.mm b/osdep/MacDNSHelper.mm index 38e74dc3f..8a5bebd92 100644 --- a/osdep/MacDNSHelper.mm +++ b/osdep/MacDNSHelper.mm @@ -6,6 +6,11 @@ namespace ZeroTier { +static void printKeys (const void* key, const void* value, void* context) { + CFShow(key); + CFShow(value); +} + void MacDNSHelper::setDNS(uint64_t nwid, const char *domain, const std::vector &servers) { SCDynamicStoreRef ds = SCDynamicStoreCreate(NULL, CFSTR("zerotier"), NULL, NULL); @@ -85,4 +90,130 @@ void MacDNSHelper::removeDNS(uint64_t nwid) CFRelease(ds); } -} \ No newline at end of file +// Make macOS believe we do in fact have ipv6 connectivity and that it should resolve dns names +// over ipv6 if we ask for them. +// Originally I planned to put all the v6 ip addresses from the network into the config. +// But only the link local address is necessary and sufficient. Added other v6 addresses +// doesn't do anything. +bool MacDNSHelper::addIps(uint64_t nwid, const MAC mac, const char *dev, const std::vector& addrs) +{ + + bool hasV6 = false; + for (unsigned int i = 0; i < addrs.size(); ++i) { + if (addrs[i].isV6()) { + hasV6 = true; + break; + } + } + + if (!hasV6) { + MacDNSHelper::removeIps(nwid); + return true; + } + + + SCDynamicStoreRef ds = SCDynamicStoreCreate(NULL, CFSTR("zerotier"), NULL, NULL); + char buf[256] = { 0 }; + sprintf(buf, "State:/Network/Service/%.16llx/IPv6", nwid); + + InetAddress ll = InetAddress::makeIpv6LinkLocal(mac); + char buf2[256] = {0}; + const char* llStr = ll.toIpString(buf2); + + + CFStringRef key = CFStringCreateWithCString(NULL, buf, kCFStringEncodingUTF8); + CFStringRef* cfaddrs = new CFStringRef[1]; + CFStringRef* cfprefixes = new CFStringRef[1]; + CFStringRef* cfdestaddrs = new CFStringRef[1]; + CFStringRef* cfflags = new CFStringRef[1]; + + + cfaddrs[0] = CFStringCreateWithCString(NULL, llStr, kCFStringEncodingUTF8); + cfprefixes[0] = CFStringCreateWithCString(NULL, "64", kCFStringEncodingUTF8); + cfdestaddrs[0] = CFStringCreateWithCString(NULL, "::ffff:ffff:ffff:ffff:0:0", kCFStringEncodingUTF8); + cfflags[0] = CFStringCreateWithCString(NULL, "0", kCFStringEncodingUTF8); + + CFArrayRef addrArray = CFArrayCreate(NULL, (const void**)cfaddrs, 1, &kCFTypeArrayCallBacks); + CFArrayRef prefixArray = CFArrayCreate(NULL, (const void**)cfprefixes, 1, &kCFTypeArrayCallBacks); + CFArrayRef destArray = CFArrayCreate(NULL, (const void**)cfdestaddrs, 1, &kCFTypeArrayCallBacks); + CFArrayRef flagsArray = CFArrayCreate(NULL, (const void**)cfflags, 1, &kCFTypeArrayCallBacks); + CFStringRef cfdev = CFStringCreateWithCString(NULL, dev, kCFStringEncodingUTF8); + + const int SIZE = 5; + CFStringRef keys[SIZE]; + keys[0] = CFSTR("Addresses"); + keys[1] = CFSTR("DestAddresses"); + keys[2] = CFSTR("Flags"); + keys[3] = CFSTR("InterfaceName"); + keys[4] = CFSTR("PrefixLength"); + + CFTypeRef values[SIZE]; + values[0] = addrArray; + values[1] = destArray; + values[2] = flagsArray; + // values[3] = devArray; + values[3] = cfdev; + values[4] = prefixArray; + + + CFDictionaryRef dict = CFDictionaryCreate(NULL, + (const void**)keys, (const void**)values, SIZE, &kCFCopyStringDictionaryKeyCallBacks, + &kCFTypeDictionaryValueCallBacks); + + // CFDictionaryApplyFunction(dict, printKeys, NULL); + + CFArrayRef list = SCDynamicStoreCopyKeyList(ds, key); + CFIndex i = 0, j = CFArrayGetCount(list); + bool addrsChanged = true; + CFPropertyListRef oldAddrs = NULL; + + bool ret = TRUE; + if (j > 0) { + oldAddrs = SCDynamicStoreCopyValue(ds, (CFStringRef)CFArrayGetValueAtIndex(list, i)); + addrsChanged = !CFEqual(oldAddrs,dict); + } + if (addrsChanged) { + if (j <= 0) { + ret &= SCDynamicStoreAddValue(ds, key, dict); + } else { + ret &= SCDynamicStoreSetValue(ds, (CFStringRef)CFArrayGetValueAtIndex(list, i), dict); + } + if (!ret) { + fprintf(stderr, "Error writing IPv6 configuration\n"); + } + } + + CFRelease(addrArray); + CFRelease(prefixArray); + CFRelease(destArray); + CFRelease(flagsArray); + CFRelease(cfdev); + + CFRelease(list); + CFRelease(dict); + + CFRelease(ds); + CFRelease(key); + + delete[] cfaddrs; + delete[] cfprefixes; + delete[] cfdestaddrs; + delete[] cfflags; + + return ret; +} +bool MacDNSHelper::removeIps(uint64_t nwid) +{ + SCDynamicStoreRef ds = SCDynamicStoreCreate(NULL, CFSTR("zerotier"), NULL, NULL); + + char buf[256] = {0}; + sprintf(buf, "State:/Network/Service/%.16llx/IPv6", nwid); + CFStringRef key = CFStringCreateWithCString(NULL, buf, kCFStringEncodingUTF8); + bool res = SCDynamicStoreRemoveValue(ds, key); + CFRelease(key); + CFRelease(ds); + + return res; +} + +} diff --git a/osdep/MacEthernetTap.cpp b/osdep/MacEthernetTap.cpp index 1ba82dcb7..55822fd5a 100644 --- a/osdep/MacEthernetTap.cpp +++ b/osdep/MacEthernetTap.cpp @@ -244,6 +244,7 @@ MacEthernetTap::~MacEthernetTap() pid_t pid0,pid1; MacDNSHelper::removeDNS(_nwid); + MacDNSHelper::removeIps(_nwid); Mutex::Lock _gl(globalTapCreateLock); ::write(_shutdownSignalPipe[1],"\0",1); // causes thread to exit diff --git a/service/OneService.cpp b/service/OneService.cpp index 255bad21e..68891b8e5 100644 --- a/service/OneService.cpp +++ b/service/OneService.cpp @@ -2041,6 +2041,11 @@ public: fprintf(stderr,"ERROR: unable to add ip address %s" ZT_EOL_S, ip->toString(ipbuf)); } } + +#ifdef __APPLE__ + if (!MacDNSHelper::addIps(n.config.nwid, n.config.mac, n.tap->deviceName().c_str(), newManagedIps)) + fprintf(stderr, "ERROR: unable to add v6 addresses to system configuration" ZT_EOL_S); +#endif #endif n.managedIps.swap(newManagedIps); } From 1c6fd4125d6a66a4316559437f67dec6e33f4c62 Mon Sep 17 00:00:00 2001 From: Joseph Henry Date: Tue, 14 Dec 2021 11:49:43 -0800 Subject: [PATCH 5/9] Fix custom policy parsing bug mentioned in issue #1507 --- node/Bond.cpp | 2 +- node/Bond.hpp | 4 ++-- service/OneService.cpp | 6 ++++-- 3 files changed, 7 insertions(+), 5 deletions(-) diff --git a/node/Bond.cpp b/node/Bond.cpp index 05bd7a842..a5b3d1b03 100644 --- a/node/Bond.cpp +++ b/node/Bond.cpp @@ -95,7 +95,6 @@ SharedPtr Bond::createTransportTriggeredBond(const RuntimeEnvironment* ren int64_t identity = peer->identity().address().toInt(); Bond* bond = nullptr; if (! _bonds.count(identity)) { - std::string policyAlias; if (! _policyTemplateAssignments.count(identity)) { if (_defaultPolicy) { bond = new Bond(renv, _defaultPolicy, peer); @@ -1717,6 +1716,7 @@ void Bond::setBondParameters(int policy, SharedPtr templateBond, bool useT /* If a user has specified custom parameters for this bonding policy, overlay them onto the defaults */ if (useTemplate) { _policyAlias = templateBond->_policyAlias; + _policy = templateBond->policy(); _failoverInterval = templateBond->_failoverInterval >= ZT_BOND_FAILOVER_MIN_INTERVAL ? templateBond->_failoverInterval : ZT_BOND_FAILOVER_MIN_INTERVAL; _downDelay = templateBond->_downDelay; _upDelay = templateBond->_upDelay; diff --git a/node/Bond.hpp b/node/Bond.hpp index f9f85beed..11e5980da 100644 --- a/node/Bond.hpp +++ b/node/Bond.hpp @@ -1000,12 +1000,12 @@ class Bond { /** * @param policy Bonding policy for this bond */ - /* + inline void setPolicy(uint8_t policy) { _policy = policy; } -*/ + /** * @return the current bonding policy */ diff --git a/service/OneService.cpp b/service/OneService.cpp index 255bad21e..c451af69c 100644 --- a/service/OneService.cpp +++ b/service/OneService.cpp @@ -1769,7 +1769,8 @@ public: if (basePolicyStr.empty()) { fprintf(stderr, "error: no base policy was specified for custom policy (%s)\n", customPolicyStr.c_str()); } - if (_node->bondController()->getPolicyCodeByStr(basePolicyStr) == ZT_BOND_POLICY_NONE) { + int basePolicyCode = _node->bondController()->getPolicyCodeByStr(basePolicyStr); + if (basePolicyCode == ZT_BOND_POLICY_NONE) { fprintf(stderr, "error: custom policy (%s) is invalid, unknown base policy (%s).\n", customPolicyStr.c_str(), basePolicyStr.c_str()); continue; @@ -1781,6 +1782,7 @@ public: // New bond, used as a copy template for new instances SharedPtr newTemplateBond = new Bond(NULL, basePolicyStr, customPolicyStr, SharedPtr()); // Acceptable ranges + newTemplateBond->setPolicy(basePolicyCode); newTemplateBond->setMaxAcceptableLatency(OSUtils::jsonInt(customPolicy["maxAcceptableLatency"],-1)); newTemplateBond->setMaxAcceptableMeanLatency(OSUtils::jsonInt(customPolicy["maxAcceptableMeanLatency"],-1)); newTemplateBond->setMaxAcceptablePacketDelayVariance(OSUtils::jsonInt(customPolicy["maxAcceptablePacketDelayVariance"],-1)); @@ -1805,7 +1807,7 @@ public: newTemplateBond->setUpDelay(OSUtils::jsonInt(customPolicy["upDelay"],-1)); newTemplateBond->setDownDelay(OSUtils::jsonInt(customPolicy["downDelay"],-1)); newTemplateBond->setFlowRebalanceStrategy(OSUtils::jsonInt(customPolicy["flowRebalanceStrategy"],(uint64_t)0)); - newTemplateBond->setFailoverInterval(OSUtils::jsonInt(customPolicy["failoverInterval"],(uint64_t)0)); + newTemplateBond->setFailoverInterval(OSUtils::jsonInt(customPolicy["failoverInterval"],ZT_BOND_FAILOVER_DEFAULT_INTERVAL)); newTemplateBond->setPacketsPerLink(OSUtils::jsonInt(customPolicy["packetsPerLink"],-1)); // Policy-Specific link set From b154b7296c8b57493a0c60e50f2fe675c62a6528 Mon Sep 17 00:00:00 2001 From: Joseph Henry Date: Tue, 14 Dec 2021 21:13:19 -0800 Subject: [PATCH 6/9] Improve multipath logging output --- node/Bond.cpp | 210 +++++++++++++++++--------------------------------- node/Bond.hpp | 3 + 2 files changed, 73 insertions(+), 140 deletions(-) diff --git a/node/Bond.cpp b/node/Bond.cpp index a5b3d1b03..dde6e22b6 100644 --- a/node/Bond.cpp +++ b/node/Bond.cpp @@ -16,6 +16,7 @@ #include #include +#include namespace ZeroTier { @@ -102,7 +103,7 @@ SharedPtr Bond::createTransportTriggeredBond(const RuntimeEnvironment* ren } if (! _defaultPolicy && _defaultPolicyStr.length()) { bond = new Bond(renv, _bondPolicyTemplates[_defaultPolicyStr].ptr(), peer); - bond->log("new default custom bond"); + bond->log("new default custom bond (based on %s)", bond->getPolicyStrByCode(bond->policy()).c_str()); } } else { @@ -147,14 +148,12 @@ SharedPtr Bond::createTransportTriggeredBond(const RuntimeEnvironment* ren SharedPtr Bond::getLinkBySocket(const std::string& policyAlias, uint64_t localSocket) { Mutex::Lock _l(_links_m); - char ifname[32] = { 0 }; // 256 because interfaces on Windows can potentially be that long + char ifname[64] = { 0 }; _phy->getIfName((PhySocket*)((uintptr_t)localSocket), ifname, sizeof(ifname) - 1); - // fprintf(stderr, "ifname %s\n",ifname); std::string ifnameStr(ifname); auto search = _interfaceToLinkMap[policyAlias].find(ifnameStr); if (search == _interfaceToLinkMap[policyAlias].end()) { // If the link wasn't already known, add a new entry - // fprintf(stderr, "adding new link?? %s\n", ifnameStr.c_str()); SharedPtr s = new Link(ifnameStr, 0, 0, true, ZT_BOND_SLAVE_MODE_SPARE, "", 0.0); _interfaceToLinkMap[policyAlias].insert(std::pair >(ifnameStr, s)); return s; @@ -182,7 +181,6 @@ void Bond::processBackgroundTasks(void* tPtr, const int64_t now) while (bondItr != _bonds.end()) { // Update Bond Controller's background processing timer _currMinReqMonitorInterval = std::min(_currMinReqMonitorInterval, (unsigned long)(bondItr->second->monitorInterval())); - // Process bond tasks bondItr->second->processBackgroundBondTasks(tPtr, now); ++bondItr; } @@ -215,8 +213,6 @@ Bond::Bond(const RuntimeEnvironment* renv, SharedPtr originalBond, const S void Bond::nominatePathToBond(const SharedPtr& path, int64_t now) { - char pathStr[64] = { 0 }; - path->address().toString(pathStr); Mutex::Lock _l(_paths_m); /** * Ensure the link is allowed and the path is not already present @@ -260,7 +256,7 @@ void Bond::nominatePathToBond(const SharedPtr& path, int64_t now) _paths[i].enabled = sl->enabled(); _paths[i].onlyPathOnLink = ! bFoundCommonLink; } - log("nominate link %s/%s (now in trial period)", getLink(path)->ifname().c_str(), pathStr); + log("nominate link %s", pathToStr(path).c_str()); break; } } @@ -364,9 +360,6 @@ SharedPtr Bond::getAppropriatePath(int64_t now, int32_t flowId) void Bond::recordIncomingInvalidPacket(const SharedPtr& path) { - // char pathStr[64] = { 0 }; path->address().toString(pathStr); - // log("%s (qos) Invalid packet on link %s/%s from peer %llx", - // getLink(path)->ifname().c_str(), pathStr); Mutex::Lock _l(_paths_m); for (int i = 0; i < ZT_MAX_PEER_NETWORK_PATHS; ++i) { if (_paths[i].p == path) { @@ -379,13 +372,6 @@ void Bond::recordOutgoingPacket(const SharedPtr& path, uint64_t packetId, { _freeRandomByte += (unsigned char)(packetId >> 8); // Grab entropy to use in path selection logic bool isFrame = (verb == Packet::Packet::VERB_ECHO || verb == Packet::VERB_FRAME || verb == Packet::VERB_EXT_FRAME); - if (isFrame) { - // char pathStr[64] = { 0 }; - // path->address().toString(pathStr); - // int pathIdx = getNominatedPathIdx(path); - // log("outgoing packet via [%d]", pathIdx); - // log("outgoing packet via %s/%s", getLink(path)->ifname().c_str(), pathStr); - } bool shouldRecord = (packetId & (ZT_QOS_ACK_DIVISOR - 1) && (verb != Packet::VERB_ACK) && (verb != Packet::VERB_QOS_MEASUREMENT)); if (isFrame || shouldRecord) { Mutex::Lock _l(_paths_m); @@ -416,12 +402,6 @@ void Bond::recordOutgoingPacket(const SharedPtr& path, uint64_t packetId, void Bond::recordIncomingPacket(const SharedPtr& path, uint64_t packetId, uint16_t payloadLength, Packet::Verb verb, int32_t flowId, int64_t now) { bool isFrame = (verb == Packet::Packet::VERB_ECHO || verb == Packet::VERB_FRAME || verb == Packet::VERB_EXT_FRAME); - if (isFrame) { - // char pathStr[64] = { 0 }; path->address().toString(pathStr); - // int pathIdx = getNominatedPathIdx(path); - // log("incoming packet via [%d] [id=%llx, len=%d, verb=%d, flowId=%x]", pathIdx, packetId, payloadLength, verb, flowId); - // log("incoming packet via %s/%s (ls=%llx) [id=%llx, len=%d, verb=%d, flowId=%x]", getLink(path)->ifname().c_str(), pathStr, path->localSocket(), packetId, payloadLength, verb, flowId); - } bool shouldRecord = (packetId & (ZT_QOS_ACK_DIVISOR - 1) && (verb != Packet::VERB_ACK) && (verb != Packet::VERB_QOS_MEASUREMENT)); Mutex::Lock _l(_paths_m); int pathIdx = getNominatedPathIdx(path); @@ -473,8 +453,7 @@ void Bond::receivedQoS(const SharedPtr& path, int64_t now, int count, uint if (pathIdx == ZT_MAX_PEER_NETWORK_PATHS) { return; } - // char pathStr[64] = { 0 }; path->address().toString(pathStr); - // log("received QoS packet (sampling %d frames) via %s/%s", count, getLink(path)->ifname().c_str(), pathStr); + // log("received QoS packet (sampling %d frames) via %s", count, pathToStr(path).c_str()); // Look up egress times and compute latency values for each record std::map::iterator it; for (int j = 0; j < count; j++) { @@ -509,12 +488,9 @@ int32_t Bond::generateQoSPacket(int pathIdx, int64_t now, char* qosBuffer) bool Bond::assignFlowToBondedPath(SharedPtr& flow, int64_t now) { - char curPathStr[64] = { 0 }; unsigned int idx = ZT_MAX_PEER_NETWORK_PATHS; if (_policy == ZT_BOND_POLICY_BALANCE_XOR) { idx = abs((int)(flow->id % (_numBondedPaths))); - SharedPtr link = RR->bc->getLinkBySocket(_policyAlias, _paths[_bondIdxMap[idx]].p->localSocket()); - _paths[_bondIdxMap[idx]].p->address().toString(curPathStr); flow->assignPath(_bondIdxMap[idx], now); ++(_paths[_bondIdxMap[idx]].assignedFlowCount); } @@ -541,8 +517,6 @@ bool Bond::assignFlowToBondedPath(SharedPtr& flow, int64_t now) entropy %= totalIncompleteAllocation; for (unsigned int i = 0; i < ZT_MAX_PEER_NETWORK_PATHS; ++i) { if (_paths[i].p && _paths[i].bonded) { - SharedPtr link = RR->bc->getLinkBySocket(_policyAlias, _paths[i].p->localSocket()); - _paths[i].p->address().toString(curPathStr); uint8_t probabilitySegment = (_totalBondUnderload > 0) ? _paths[i].affinity : _paths[i].allocation; if (entropy <= probabilitySegment) { idx = i; @@ -566,15 +540,13 @@ bool Bond::assignFlowToBondedPath(SharedPtr& flow, int64_t now) } flow->assignPath(_abPathIdx, now); } - _paths[flow->assignedPath].p->address().toString(curPathStr); SharedPtr link = RR->bc->getLinkBySocket(_policyAlias, _paths[flow->assignedPath].p->localSocket()); - log("assign out-flow %x to link %s/%s (%lu / %lu flows)", flow->id, link->ifname().c_str(), curPathStr, _paths[flow->assignedPath].assignedFlowCount, (unsigned long)_flows.size()); + log("assign out-flow %04x to link %s (%lu / %lu flows)", flow->id, pathToStr(_paths[flow->assignedPath].p).c_str(), _paths[flow->assignedPath].assignedFlowCount, (unsigned long)_flows.size()); return true; } SharedPtr Bond::createFlow(int pathIdx, int32_t flowId, unsigned char entropy, int64_t now) { - char curPathStr[64] = { 0 }; if (! _numBondedPaths) { log("unable to assign flow %x (bond has no links)\n", flowId); return SharedPtr(); @@ -592,10 +564,8 @@ SharedPtr Bond::createFlow(int pathIdx, int32_t flowId, unsigned cha */ if (pathIdx != ZT_MAX_PEER_NETWORK_PATHS) { flow->assignPath(pathIdx, now); - _paths[pathIdx].p->address().toString(curPathStr); _paths[pathIdx].assignedFlowCount++; - SharedPtr link = RR->bc->getLinkBySocket(_policyAlias, _paths[flow->assignedPath].p->localSocket()); - log("assign in-flow %x to link %s/%s (%lu / %lu)", flow->id, link->ifname().c_str(), curPathStr, _paths[pathIdx].assignedFlowCount, (unsigned long)_flows.size()); + log("assign in-flow %x to link %s (%lu / %lu)", flow->id, pathToStr(_paths[pathIdx].p).c_str(), _paths[pathIdx].assignedFlowCount, (unsigned long)_flows.size()); } /** * Add a flow when no path was provided. This means that it is an outgoing packet @@ -679,7 +649,6 @@ void Bond::processIncomingPathNegotiationRequest(uint64_t now, SharedPtr& void Bond::pathNegotiationCheck(void* tPtr, int64_t now) { - char pathStr[64] = { 0 }; int maxInPathIdx = ZT_MAX_PEER_NETWORK_PATHS; int maxOutPathIdx = ZT_MAX_PEER_NETWORK_PATHS; uint64_t maxInCount = 0; @@ -717,8 +686,6 @@ void Bond::pathNegotiationCheck(void* tPtr, int64_t now) sendPATH_NEGOTIATION_REQUEST(tPtr, _paths[maxOutPathIdx].p); ++_numSentPathNegotiationRequests; _lastSentPathNegotiationRequest = now; - _paths[maxOutPathIdx].p->address().toString(pathStr); - SharedPtr link = RR->bc->getLinkBySocket(_policyAlias, _paths[maxOutPathIdx].p->localSocket()); // fprintf(stderr, "sending request to use %s on %s, ls=%llx, utility=%d\n", pathStr, link->ifname().c_str(), _paths[maxOutPathIdx].p->localSocket(), _localUtility); } } @@ -737,9 +704,7 @@ void Bond::pathNegotiationCheck(void* tPtr, int64_t now) void Bond::sendPATH_NEGOTIATION_REQUEST(void* tPtr, int pathIdx) { - char pathStr[64] = { 0 }; - _paths[pathIdx].p->address().toString(pathStr); - log("send link negotiation request to peer via link %s/%s, local utility is %d", getLink(_paths[pathIdx].p)->ifname().c_str(), pathStr, _localUtility); + log("send link negotiation request to peer via link %s, local utility is %d", pathToStr(_paths[pathIdx].p).c_str(), _localUtility); if (_abLinkSelectMethod != ZT_BOND_RESELECTION_POLICY_OPTIMIZE) { return; } @@ -753,8 +718,6 @@ void Bond::sendPATH_NEGOTIATION_REQUEST(void* tPtr, int pathIdx) void Bond::sendQOS_MEASUREMENT(void* tPtr, int pathIdx, int64_t localSocket, const InetAddress& atAddress, int64_t now) { - char pathStr[64] = { 0 }; - _paths[pathIdx].p->address().toString(pathStr); int64_t _now = RR->node->now(); Packet outp(_peer->_id.address(), RR->identity.address(), Packet::VERB_QOS_MEASUREMENT); char qosData[ZT_QOS_MAX_PACKET_SIZE]; @@ -772,7 +735,7 @@ void Bond::sendQOS_MEASUREMENT(void* tPtr, int pathIdx, int64_t localSocket, con _paths[pathIdx].packetsReceivedSinceLastQoS = 0; _paths[pathIdx].lastQoSMeasurement = now; } - // log("send QOS via link %s/%s (len=%d)", getLink(_paths[pathIdx].p)->ifname().c_str(), pathStr, len); + // log("send QOS via link %s (len=%d)", pathToStr(_paths[pathIdx].p).c_str(), len); } void Bond::processBackgroundBondTasks(void* tPtr, int64_t now) @@ -793,17 +756,14 @@ void Bond::processBackgroundBondTasks(void* tPtr, int64_t now) // Send ambient monitoring traffic for (unsigned int i = 0; i < ZT_MAX_PEER_NETWORK_PATHS; ++i) { if (_paths[i].p && _paths[i].allowed()) { - // ECHO (this is our bond's heartbeat) if ((_monitorInterval > 0) && ((now - _paths[i].p->_lastOut) >= _monitorInterval)) { if ((_peer->remoteVersionProtocol() >= 5) && (! ((_peer->remoteVersionMajor() == 1) && (_peer->remoteVersionMinor() == 1) && (_peer->remoteVersionRevision() == 0)))) { - Packet outp(_peer->address(), RR->identity.address(), Packet::VERB_ECHO); + Packet outp(_peer->address(), RR->identity.address(), Packet::VERB_ECHO); // ECHO (this is our bond's heartbeat) outp.armor(_peer->key(), true, _peer->aesKeysIfSupported()); RR->node->expectReplyTo(outp.packetId()); RR->node->putPacket(tPtr, _paths[i].p->localSocket(), _paths[i].p->address(), outp.data(), outp.size()); _overheadBytes += outp.size(); - char pathStr[64] = { 0 }; - _paths[i].p->address().toString(pathStr); - // log("send HELLO via link %s/%s (len=%d)", getLink(_paths[i].p)->ifname().c_str(), pathStr, outp.size()); + log("sent ECHO via link %s", pathToStr(_paths[i].p).c_str()); } } // QOS @@ -836,7 +796,6 @@ void Bond::processBackgroundBondTasks(void* tPtr, int64_t now) void Bond::curateBond(int64_t now, bool rebuildBond) { - char pathStr[64] = { 0 }; uint8_t tmpNumAliveLinks = 0; uint8_t tmpNumTotalLinks = 0; /** @@ -854,7 +813,7 @@ void Bond::curateBond(int64_t now, bool rebuildBond) } /** - * Determine alive-ness + * Determine aliveness */ _paths[i].alive = (now - _paths[i].p->_lastIn) < _failoverInterval; @@ -879,12 +838,11 @@ void Bond::curateBond(int64_t now, bool rebuildBond) * Note eligibility state change (if any) and take appropriate action */ if (currEligibility != _paths[i].eligible) { - _paths[i].p->address().toString(pathStr); if (currEligibility == 0) { - log("link %s/%s is no longer eligible", getLink(_paths[i].p)->ifname().c_str(), pathStr); + log("link %s is no longer eligible", pathToStr(_paths[i].p).c_str()); } if (currEligibility == 1) { - log("link %s/%s is eligible", getLink(_paths[i].p)->ifname().c_str(), pathStr); + log("link %s is eligible", pathToStr(_paths[i].p).c_str()); } dumpPathStatus(now, i); if (currEligibility) { @@ -894,8 +852,7 @@ void Bond::curateBond(int64_t now, bool rebuildBond) _paths[i].adjustRefractoryPeriod(now, _defaultPathRefractoryPeriod, ! currEligibility); if (_paths[i].bonded) { if (_allowFlowHashing) { - _paths[i].p->address().toString(pathStr); - log("link %s/%s was bonded, flow reallocation will occur soon", getLink(_paths[i].p)->ifname().c_str(), pathStr); + log("link %s was bonded, flow reallocation will occur soon", pathToStr(_paths[i].p).c_str()); rebuildBond = true; _paths[i].shouldReallocateFlows = _paths[i].bonded; } @@ -916,19 +873,13 @@ void Bond::curateBond(int64_t now, bool rebuildBond) _numTotalLinks = tmpNumTotalLinks; bool tmpHealthStatus = true; - if (_policy == ZT_BOND_POLICY_ACTIVE_BACKUP) { - if (_numAliveLinks < 2) { - // Considered healthy if there is at least one backup link - tmpHealthStatus = false; - } - } if (_policy == ZT_BOND_POLICY_BROADCAST) { if (_numAliveLinks < 1) { // Considered healthy if we're able to send frames at all tmpHealthStatus = false; } } - if ((_policy == ZT_BOND_POLICY_BALANCE_RR) || (_policy == ZT_BOND_POLICY_BALANCE_XOR) || (_policy == ZT_BOND_POLICY_BALANCE_AWARE)) { + if ((_policy == ZT_BOND_POLICY_BALANCE_RR) || (_policy == ZT_BOND_POLICY_BALANCE_XOR) || (_policy == ZT_BOND_POLICY_BALANCE_AWARE || (_policy == ZT_BOND_POLICY_ACTIVE_BACKUP))) { if (_numAliveLinks < _numTotalLinks) { tmpHealthStatus = false; } @@ -941,7 +892,7 @@ void Bond::curateBond(int64_t now, bool rebuildBond) else { healthStatusStr = "DEGRADED"; } - log("bond is in a %s state (links: %d/%d)", healthStatusStr.c_str(), _numAliveLinks, _numTotalLinks); + log("bond is %s (%d/%d links)", healthStatusStr.c_str(), _numAliveLinks, _numTotalLinks); dumpInfo(now, true); } @@ -958,7 +909,6 @@ void Bond::curateBond(int64_t now, bool rebuildBond) } if (rebuildBond) { log("rebuilding bond"); - // TODO: Obey blacklisting int updatedBondedPathCount = 0; // Build map associating paths with local physical links. Will be selected from in next step std::map, std::vector > linkMap; @@ -983,8 +933,7 @@ void Bond::curateBond(int64_t now, bool rebuildBond) } addPathToBond(idx, updatedBondedPathCount); ++updatedBondedPathCount; - _paths[idx].p->address().toString(pathStr); - log("add %s/%s (no user addr preference)", link->ifname().c_str(), pathStr); + log("add %s (no user addr preference)", pathToStr(_paths[idx].p).c_str()); } } // If the user prefers to only use one address type (IPv4 or IPv6) @@ -995,14 +944,12 @@ void Bond::curateBond(int64_t now, bool rebuildBond) continue; } if (! _paths[idx].allowed()) { - _paths[idx].p->address().toString(pathStr); - log("did not add %s/%s (user addr preference %d)", link->ifname().c_str(), pathStr, ipvPref); + log("did not add %s (user addr preference %d)", pathToStr(_paths[idx].p).c_str(), ipvPref); continue; } addPathToBond(idx, updatedBondedPathCount); ++updatedBondedPathCount; - _paths[idx].p->address().toString(pathStr); - log("add path %s/%s (user addr preference %d)", link->ifname().c_str(), pathStr, ipvPref); + log("add path %s (user addr preference %d)", pathToStr(_paths[idx].p).c_str(), ipvPref); } } // If the users prefers one address type to another, try to find at least @@ -1018,8 +965,7 @@ void Bond::curateBond(int64_t now, bool rebuildBond) if (_paths[idx].preferred()) { addPathToBond(idx, updatedBondedPathCount); ++updatedBondedPathCount; - _paths[idx].p->address().toString(pathStr); - log("add %s/%s (user addr preference %d)", link->ifname().c_str(), pathStr, ipvPref); + log("add %s (user addr preference %d)", pathToStr(_paths[idx].p).c_str(), ipvPref); foundPreferredPath = true; } } @@ -1033,8 +979,7 @@ void Bond::curateBond(int64_t now, bool rebuildBond) } addPathToBond(idx, updatedBondedPathCount); ++updatedBondedPathCount; - _paths[idx].p->address().toString(pathStr); - log("add %s/%s (user addr preference %d)", link->ifname().c_str(), pathStr, ipvPref); + log("add %s (user addr preference %d)", pathToStr(_paths[idx].p).c_str(), ipvPref); foundPreferredPath = true; } } @@ -1150,8 +1095,6 @@ void Bond::estimatePathQuality(int64_t now) void Bond::processBalanceTasks(int64_t now) { - char pathStr[64] = { 0 }; - if (_allowFlowHashing) { /** * Clean up and reset flows if necessary @@ -1176,8 +1119,7 @@ void Bond::processBalanceTasks(int64_t now) continue; } if (! _paths[i].eligible && _paths[i].shouldReallocateFlows) { - _paths[i].p->address().toString(pathStr); - log("reallocate flows from dead link %s/%s", getLink(_paths[i].p)->ifname().c_str(), pathStr); + log("reallocate flows from dead link %s", pathToStr(_paths[i].p).c_str()); std::map >::iterator flow_it = _flows.begin(); while (flow_it != _flows.end()) { if (_paths[flow_it->second->assignedPath].p == _paths[i].p) { @@ -1213,8 +1155,7 @@ void Bond::processBalanceTasks(int64_t now) continue; } if (_paths[i].p && _paths[i].bonded && _paths[i].eligible && (_paths[i].allocation < minimumAllocationValue) && _paths[i].assignedFlowCount) { - _paths[i].p->address().toString(pathStr); - log("reallocate flows from under-performing link %s/%s\n", getLink(_paths[i].p)->ifname().c_str(), pathStr); + log("reallocate flows from under-performing link %s\n", pathToStr(_paths[i].p).c_str()); std::map >::iterator flow_it = _flows.begin(); while (flow_it != _flows.end()) { if (flow_it->second->assignedPath == _paths[i].p) { @@ -1248,14 +1189,10 @@ void Bond::dequeueNextActiveBackupPath(uint64_t now) bool Bond::abForciblyRotateLink() { - char prevPathStr[64]; - char curPathStr[64]; if (_policy == ZT_BOND_POLICY_ACTIVE_BACKUP) { int prevPathIdx = _abPathIdx; - _paths[_abPathIdx].p->address().toString(prevPathStr); dequeueNextActiveBackupPath(RR->node->now()); - _paths[_abPathIdx].p->address().toString(curPathStr); - log("forcibly rotate link from %s/%s to %s/%s", getLink(_paths[prevPathIdx].p)->ifname().c_str(), prevPathStr, getLink(_paths[_abPathIdx].p)->ifname().c_str(), curPathStr); + log("active link rotated from %s to %s", pathToStr(_paths[prevPathIdx].p).c_str(), pathToStr(_paths[_abPathIdx].p).c_str()); return true; } return false; @@ -1263,9 +1200,6 @@ bool Bond::abForciblyRotateLink() void Bond::processActiveBackupTasks(void* tPtr, int64_t now) { - char pathStr[64] = { 0 }; - char prevPathStr[64]; - char curPathStr[64]; int prevActiveBackupPathIdx = _abPathIdx; int nonPreferredPathIdx; bool bFoundPrimaryLink = false; @@ -1279,11 +1213,10 @@ void Bond::processActiveBackupTasks(void* tPtr, int64_t now) log("no active link"); } else if (_paths[_abPathIdx].p) { - _paths[_abPathIdx].p->address().toString(curPathStr); - log("active link is %s/%s, failover queue size is %zu", getLink(_paths[_abPathIdx].p)->ifname().c_str(), curPathStr, _abFailoverQueue.size()); + log("active link is %s, failover queue size is %zu", pathToStr(_paths[_abPathIdx].p).c_str(), _abFailoverQueue.size()); } if (_abFailoverQueue.empty()) { - log("failover queue is empty, no longer fault-tolerant"); + log("failover queue is empty, bond is no longer fault-tolerant"); } } @@ -1303,10 +1236,9 @@ void Bond::processActiveBackupTasks(void* tPtr, int64_t now) log("no user-specified links"); for (int i = 0; i < ZT_MAX_PEER_NETWORK_PATHS; ++i) { if (_paths[i].p && _paths[i].eligible) { - _paths[i].p->address().toString(curPathStr); SharedPtr link = RR->bc->getLinkBySocket(_policyAlias, _paths[i].p->localSocket()); if (link) { - log("found eligible link %s/%s", getLink(_paths[i].p)->ifname().c_str(), curPathStr); + log("found eligible link %s", pathToStr(_paths[i].p).c_str()); _abPathIdx = i; break; } @@ -1326,18 +1258,16 @@ void Bond::processActiveBackupTasks(void* tPtr, int64_t now) SharedPtr link = RR->bc->getLinkBySocket(_policyAlias, _paths[i].p->localSocket()); if (_paths[i].eligible && link->primary()) { if (! _paths[i].preferred()) { - _paths[i].p->address().toString(curPathStr); // Found path on primary link, take note in case we don't find a preferred path nonPreferredPathIdx = i; bFoundPrimaryLink = true; } if (_paths[i].preferred()) { _abPathIdx = i; - _paths[_abPathIdx].p->address().toString(curPathStr); bFoundPrimaryLink = true; SharedPtr link = RR->bc->getLinkBySocket(_policyAlias, _paths[_abPathIdx].p->localSocket()); if (link) { - log("found preferred primary link %s/%s", getLink(_paths[_abPathIdx].p)->ifname().c_str(), curPathStr); + log("found preferred primary link %s", pathToStr(_paths[_abPathIdx].p).c_str()); } break; // Found preferred path on primary link } @@ -1363,8 +1293,7 @@ void Bond::processActiveBackupTasks(void* tPtr, int64_t now) if (_abPathIdx != ZT_MAX_PEER_NETWORK_PATHS) { SharedPtr link = RR->bc->getLinkBySocket(_policyAlias, _paths[_abPathIdx].p->localSocket()); if (link) { - _paths[_abPathIdx].p->address().toString(curPathStr); - log("select non-primary link %s/%s", getLink(_paths[_abPathIdx].p)->ifname().c_str(), curPathStr); + log("select non-primary link %s", pathToStr(_paths[_abPathIdx].p).c_str()); } } } @@ -1379,11 +1308,10 @@ void Bond::processActiveBackupTasks(void* tPtr, int64_t now) // Remove ineligible paths from the failover link queue for (std::deque::iterator it(_abFailoverQueue.begin()); it != _abFailoverQueue.end();) { if (_paths[(*it)].p && ! _paths[(*it)].eligible) { - _paths[(*it)].p->address().toString(curPathStr); SharedPtr link = RR->bc->getLinkBySocket(_policyAlias, _paths[(*it)].p->localSocket()); it = _abFailoverQueue.erase(it); if (link) { - log("link %s/%s is now ineligible, removing from failover queue (%zu links in queue)", getLink(_paths[_abPathIdx].p)->ifname().c_str(), curPathStr, _abFailoverQueue.size()); + log("link %s is ineligible, removing from failover queue (%zu links in queue)", pathToStr(_paths[_abPathIdx].p).c_str(), _abFailoverQueue.size()); } } else { @@ -1409,7 +1337,6 @@ void Bond::processActiveBackupTasks(void* tPtr, int64_t now) continue; } SharedPtr link = RR->bc->getLinkBySocket(_policyAlias, _paths[i].p->localSocket()); - _paths[i].p->address().toString(pathStr); int failoverScoreHandicap = _paths[i].failoverScore; if (_paths[i].preferred()) { @@ -1431,7 +1358,6 @@ void Bond::processActiveBackupTasks(void* tPtr, int64_t now) if (failoverLink) { for (int j = 0; j < ZT_MAX_PEER_NETWORK_PATHS; j++) { if (_paths[j].p && getLink(_paths[j].p) == failoverLink.ptr()) { - _paths[j].p->address().toString(pathStr); int inheritedHandicap = failoverScoreHandicap - 10; int newHandicap = _paths[j].failoverScore > inheritedHandicap ? _paths[j].failoverScore : inheritedHandicap; if (! _paths[j].preferred()) { @@ -1450,8 +1376,7 @@ void Bond::processActiveBackupTasks(void* tPtr, int64_t now) } if (! bFoundPathInQueue) { _abFailoverQueue.push_front(i); - _paths[i].p->address().toString(curPathStr); - log("add link %s/%s to failover queue (%zu links in queue)", getLink(_paths[_abPathIdx].p)->ifname().c_str(), curPathStr, _abFailoverQueue.size()); + log("add link %s to failover queue (%zu links in queue)", pathToStr(_paths[i].p).c_str(), _abFailoverQueue.size()); addPathToBond(0, i); } } @@ -1496,8 +1421,7 @@ void Bond::processActiveBackupTasks(void* tPtr, int64_t now) } if (! bFoundPathInQueue) { _abFailoverQueue.push_front(i); - _paths[i].p->address().toString(curPathStr); - log("add link %s/%s to failover queue (%zu links in queue)", getLink(_paths[i].p)->ifname().c_str(), curPathStr, _abFailoverQueue.size()); + log("add link %s to failover queue (%zu links in queue)", pathToStr(_paths[i].p).c_str(), _abFailoverQueue.size()); addPathToBond(0, i); } } @@ -1527,12 +1451,10 @@ void Bond::processActiveBackupTasks(void* tPtr, int64_t now) * Fulfill primary re-select obligations */ if (_paths[_abPathIdx].p && ! _paths[_abPathIdx].eligible) { // Implicit ZT_BOND_RESELECTION_POLICY_FAILURE - _paths[_abPathIdx].p->address().toString(curPathStr); - log("link %s/%s has failed, select link from failover queue (%zu links in queue)", getLink(_paths[_abPathIdx].p)->ifname().c_str(), curPathStr, _abFailoverQueue.size()); + log("link %s has failed, select link from failover queue (%zu links in queue)", pathToStr(_paths[_abPathIdx].p).c_str(), _abFailoverQueue.size()); if (! _abFailoverQueue.empty()) { dequeueNextActiveBackupPath(now); - _paths[_abPathIdx].p->address().toString(curPathStr); - log("active link switched to %s/%s", getLink(_paths[_abPathIdx].p)->ifname().c_str(), curPathStr); + log("active link switched to %s", pathToStr(_paths[_abPathIdx].p).c_str()); } else { log("failover queue is empty, no links to choose from"); @@ -1547,8 +1469,7 @@ void Bond::processActiveBackupTasks(void* tPtr, int64_t now) if (_abLinkSelectMethod == ZT_BOND_RESELECTION_POLICY_ALWAYS) { if (_paths[_abPathIdx].p && ! getLink(_paths[_abPathIdx].p)->primary() && getLink(_paths[_abFailoverQueue.front()].p)->primary()) { dequeueNextActiveBackupPath(now); - _paths[_abPathIdx].p->address().toString(curPathStr); - log("switch back to available primary link %s/%s (select: always)", getLink(_paths[_abPathIdx].p)->ifname().c_str(), curPathStr); + log("switch back to available primary link %s (select mode: always)", pathToStr(_paths[_abPathIdx].p).c_str()); } } if (_abLinkSelectMethod == ZT_BOND_RESELECTION_POLICY_BETTER) { @@ -1556,8 +1477,7 @@ void Bond::processActiveBackupTasks(void* tPtr, int64_t now) // Active backup has switched to "better" primary link according to re-select policy. if (getLink(_paths[_abFailoverQueue.front()].p)->primary() && (_paths[_abFailoverQueue.front()].failoverScore > _paths[_abPathIdx].failoverScore)) { dequeueNextActiveBackupPath(now); - _paths[_abPathIdx].p->address().toString(curPathStr); - log("switch back to user-defined primary link %s/%s (select: better)", getLink(_paths[_abPathIdx].p)->ifname().c_str(), curPathStr); + log("switch back to user-defined primary link %s (select mode: better)", pathToStr(_paths[_abPathIdx].p).c_str()); } } } @@ -1567,10 +1487,8 @@ void Bond::processActiveBackupTasks(void* tPtr, int64_t now) */ if (_paths[_abFailoverQueue.front()].negotiated) { dequeueNextActiveBackupPath(now); - _paths[_abPathIdx].p->address().toString(prevPathStr); _lastPathNegotiationCheck = now; - _paths[_abPathIdx].p->address().toString(curPathStr); - log("switch negotiated link %s/%s (select: optimize)", getLink(_paths[_abPathIdx].p)->ifname().c_str(), curPathStr); + log("switch negotiated link %s (select mode: optimize)", pathToStr(_paths[_abPathIdx].p).c_str()); } else { // Try to find a better path and automatically switch to it -- not too often, though. @@ -1583,18 +1501,12 @@ void Bond::processActiveBackupTasks(void* tPtr, int64_t now) int thresholdQuantity = (int)(ZT_BOND_ACTIVE_BACKUP_OPTIMIZE_MIN_THRESHOLD * (float)_paths[_abPathIdx].allocation); if ((failoverScoreDifference > 0) && (failoverScoreDifference > thresholdQuantity)) { SharedPtr oldPath = _paths[_abPathIdx].p; - _paths[_abPathIdx].p->address().toString(prevPathStr); dequeueNextActiveBackupPath(now); - _paths[_abPathIdx].p->address().toString(curPathStr); - log("ab", - "switch from %s/%s (score: %d) to better link %s/%s (score: %d) for peer %llx (select: optimize)", - getLink(oldPath)->ifname().c_str(), - prevPathStr, + log("switch from %s (score: %d) to better link %s (score: %d) (select mode: optimize)", + pathToStr(oldPath).c_str(), prevFScore, - getLink(_paths[_abPathIdx].p)->ifname().c_str(), - curPathStr, - newFScore, - _peerId); + pathToStr(_paths[_abPathIdx].p).c_str(), + newFScore); } } } @@ -1751,28 +1663,44 @@ SharedPtr Bond::getLink(const SharedPtr& path) return RR->bc->getLinkBySocket(_policyAlias, path->localSocket()); } +std::string Bond::pathToStr(const SharedPtr& path) +{ +#ifdef ZT_TRACE + char pathStr[64] = { 0 }; + char fullPathStr[256] = { 0 }; + path->address().toString(pathStr); + snprintf(fullPathStr, 256, "%.16llx-%s/%s", (unsigned long long)(path->localSocket()), getLink(path)->ifname().c_str(), pathStr); + return std::string(fullPathStr); +#else + return ""; +#endif +} + void Bond::dumpPathStatus(int64_t now, int pathIdx) { - char pathStr[64] = { 0 }; - _paths[pathIdx].p->address().toString(pathStr); - log("path status: [%2d] alive:%d, eli:%d, bonded:%d, flows:%6d, lat:%10.3f, jitter:%10.3f, error:%6.4f, loss:%6.4f, age:%6d alloc:%d--- (%s/%s)", +#ifdef ZT_TRACE + std::string aliveOrDead = _paths[pathIdx].alive ? std::string("alive") : std::string("dead"); + std::string eligibleOrNot = _paths[pathIdx].eligible ? std::string("eligible") : std::string("ineligible"); + std::string bondedOrNot = _paths[pathIdx].bonded ? std::string("bonded") : std::string("unbonded"); + log("path[%2d] --- %5s (%7d), %10s, %8s, flows=%-6d lat=%-8.3f pdv=%-7.3f err=%-6.4f loss=%-6.4f alloc=%-3d --- (%s)", pathIdx, - _paths[pathIdx].alive, - _paths[pathIdx].eligible, - _paths[pathIdx].bonded, + aliveOrDead.c_str(), + _paths[pathIdx].p->age(now), + eligibleOrNot.c_str(), + bondedOrNot.c_str(), _paths[pathIdx].assignedFlowCount, _paths[pathIdx].latencyMean, _paths[pathIdx].latencyVariance, _paths[pathIdx].packetErrorRatio, _paths[pathIdx].packetLossRatio, - _paths[pathIdx].p->age(now), _paths[pathIdx].allocation, - getLink(_paths[pathIdx].p)->ifname().c_str(), - pathStr); + pathToStr(_paths[pathIdx].p).c_str()); +#endif } void Bond::dumpInfo(int64_t now, bool force) { +#ifdef ZT_TRACE uint64_t timeSinceLastDump = now - _lastSummaryDump; if (! force && timeSinceLastDump < ZT_BOND_STATUS_INTERVAL) { return; @@ -1780,12 +1708,14 @@ void Bond::dumpInfo(int64_t now, bool force) _lastSummaryDump = now; float overhead = (_overheadBytes / (timeSinceLastDump / 1000.0f) / 1000.0f); _overheadBytes = 0; - log("bond status: bp: %d, fi: %d, mi: %d, ud: %d, dd: %d, flows: %lu, ambient: %f KB/s", _policy, _failoverInterval, _monitorInterval, _upDelay, _downDelay, (unsigned long)_flows.size(), overhead); + log("bond: bp=%d, fi=%d, mi=%d, ud=%d, dd=%d, flows=%lu, overhead=%f KB/s", _policy, _failoverInterval, _monitorInterval, _upDelay, _downDelay, (unsigned long)_flows.size(), overhead); for (int i = 0; i < ZT_MAX_PEER_NETWORK_PATHS; ++i) { if (_paths[i].p) { dumpPathStatus(now, i); } } + log(""); +#endif } } // namespace ZeroTier diff --git a/node/Bond.hpp b/node/Bond.hpp index 11e5980da..ec44da06b 100644 --- a/node/Bond.hpp +++ b/node/Bond.hpp @@ -518,6 +518,7 @@ class Bond { public: void dumpInfo(int64_t now, bool force); + std::string pathToStr(const SharedPtr& path); void dumpPathStatus(int64_t now, int pathIdx); SharedPtr getLink(const SharedPtr& path); @@ -1138,6 +1139,7 @@ class Bond { */ void log(const char* fmt, ...) { +#ifdef ZT_TRACE time_t rawtime; struct tm* timeinfo; char timestamp[80]; @@ -1157,6 +1159,7 @@ class Bond { va_end(args); RR->t->bondStateMessage(NULL, traceMsg); #undef MAX_MSG_LEN +#endif } private: From bdef9d3bd76e205c37fa4eeb3c8497235a72b4d7 Mon Sep 17 00:00:00 2001 From: Joseph Henry Date: Tue, 14 Dec 2021 21:20:58 -0800 Subject: [PATCH 7/9] Fix situation where too many ECHOs are sent to multipath peer --- node/Bond.cpp | 10 +++++++++- 1 file changed, 9 insertions(+), 1 deletion(-) diff --git a/node/Bond.cpp b/node/Bond.cpp index dde6e22b6..c88f22170 100644 --- a/node/Bond.cpp +++ b/node/Bond.cpp @@ -762,6 +762,7 @@ void Bond::processBackgroundBondTasks(void* tPtr, int64_t now) outp.armor(_peer->key(), true, _peer->aesKeysIfSupported()); RR->node->expectReplyTo(outp.packetId()); RR->node->putPacket(tPtr, _paths[i].p->localSocket(), _paths[i].p->address(), outp.data(), outp.size()); + _paths[i].p->_lastOut = now; _overheadBytes += outp.size(); log("sent ECHO via link %s", pathToStr(_paths[i].p).c_str()); } @@ -1708,7 +1709,14 @@ void Bond::dumpInfo(int64_t now, bool force) _lastSummaryDump = now; float overhead = (_overheadBytes / (timeSinceLastDump / 1000.0f) / 1000.0f); _overheadBytes = 0; - log("bond: bp=%d, fi=%d, mi=%d, ud=%d, dd=%d, flows=%lu, overhead=%f KB/s", _policy, _failoverInterval, _monitorInterval, _upDelay, _downDelay, (unsigned long)_flows.size(), overhead); + log("bond: bp=%d, fi=%d, mi=%d, ud=%d, dd=%d, flows=%lu, overhead=%f KB/s", + _policy, + _failoverInterval, + _monitorInterval, + _upDelay, + _downDelay, + (unsigned long)_flows.size(), + overhead); for (int i = 0; i < ZT_MAX_PEER_NETWORK_PATHS; ++i) { if (_paths[i].p) { dumpPathStatus(now, i); From 06ed114fb698c797ea4e36d8c0b5e86e7eb3eb5b Mon Sep 17 00:00:00 2001 From: Adam Ierymenko Date: Wed, 15 Dec 2021 12:32:28 -0500 Subject: [PATCH 8/9] Release notes and GitHub issue #1512 --- RELEASE-NOTES.md | 5 +++++ node/Peer.cpp | 2 +- 2 files changed, 6 insertions(+), 1 deletion(-) diff --git a/RELEASE-NOTES.md b/RELEASE-NOTES.md index 4845c68af..7718ec561 100644 --- a/RELEASE-NOTES.md +++ b/RELEASE-NOTES.md @@ -1,6 +1,11 @@ ZeroTier Release Notes ====== +# 2021-12-15 -- Version 1.8.5 + + * Fix an issue that could cause self-hosted roots ("moons") to fail to assist peers in making direct links. (GitHub issue #1512) + * Merge a series of changes by Joseph Henry (of ZeroTier) that should fix some edge cases where ZeroTier would "forget" valid paths. + # 2021-11-30 -- Version 1.8.4 * Fixed an ugly font problem on some older macOS versions. diff --git a/node/Peer.cpp b/node/Peer.cpp index ab4cb7c51..8ab51687d 100644 --- a/node/Peer.cpp +++ b/node/Peer.cpp @@ -409,7 +409,7 @@ void Peer::introduce(void *const tPtr,const int64_t now,const SharedPtr &o outp.append((uint8_t)4); outp.append(_paths[mine].p->address().rawIpData(),4); } - outp.armor(other->_key,true,aesKeysIfSupported()); + outp.armor(other->_key,true,other->aesKeysIfSupported()); other->_paths[theirs].p->send(RR,tPtr,outp.data(),outp.size(),now); } ++alt; From aeec7dae36cae6c6825f47e089d6b726b0cbef40 Mon Sep 17 00:00:00 2001 From: Andrej Binder Date: Wed, 15 Dec 2021 22:22:02 +0100 Subject: [PATCH 9/9] Prevent arithmetic error on interface change. --- node/Bond.cpp | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/node/Bond.cpp b/node/Bond.cpp index c88f22170..f74d4a570 100644 --- a/node/Bond.cpp +++ b/node/Bond.cpp @@ -488,6 +488,10 @@ int32_t Bond::generateQoSPacket(int pathIdx, int64_t now, char* qosBuffer) bool Bond::assignFlowToBondedPath(SharedPtr& flow, int64_t now) { + if (! _numBondedPaths) { + log("unable to assign flow %x (bond has no links)\n", flow->id); + return false; + } unsigned int idx = ZT_MAX_PEER_NETWORK_PATHS; if (_policy == ZT_BOND_POLICY_BALANCE_XOR) { idx = abs((int)(flow->id % (_numBondedPaths))); @@ -500,10 +504,6 @@ bool Bond::assignFlowToBondedPath(SharedPtr& flow, int64_t now) if (_totalBondUnderload) { entropy %= _totalBondUnderload; } - if (! _numBondedPaths) { - log("unable to assign flow %x (bond has no links)\n", flow->id); - return false; - } /* Since there may be scenarios where a path is removed before we can re-estimate relative qualities (and thus allocations) we need to down-modulate the entropy value that we use to randomly assign among the surviving paths, otherwise we risk