diff options
Diffstat (limited to 'node')
-rw-r--r-- | node/IncomingPacket.cpp | 180 | ||||
-rw-r--r-- | node/Membership.cpp | 29 | ||||
-rw-r--r-- | node/Multicaster.cpp | 4 | ||||
-rw-r--r-- | node/Network.cpp | 274 | ||||
-rw-r--r-- | node/NetworkConfig.cpp | 2 | ||||
-rw-r--r-- | node/NetworkConfig.hpp | 7 | ||||
-rw-r--r-- | node/Node.cpp | 3 | ||||
-rw-r--r-- | node/Node.hpp | 7 | ||||
-rw-r--r-- | node/OutboundMulticast.cpp | 13 | ||||
-rw-r--r-- | node/Packet.cpp | 44 | ||||
-rw-r--r-- | node/Packet.hpp | 33 | ||||
-rw-r--r-- | node/Peer.cpp | 57 | ||||
-rw-r--r-- | node/RuntimeEnvironment.hpp | 3 | ||||
-rw-r--r-- | node/SelfAwareness.cpp | 3 | ||||
-rw-r--r-- | node/Switch.cpp | 71 | ||||
-rw-r--r-- | node/Topology.cpp | 10 | ||||
-rw-r--r-- | node/Topology.hpp | 6 | ||||
-rw-r--r-- | node/Trace.cpp | 197 | ||||
-rw-r--r-- | node/Trace.hpp | 157 |
19 files changed, 569 insertions, 531 deletions
diff --git a/node/IncomingPacket.cpp b/node/IncomingPacket.cpp index ac8514c6..e1fb180c 100644 --- a/node/IncomingPacket.cpp +++ b/node/IncomingPacket.cpp @@ -48,6 +48,7 @@ #include "Capability.hpp" #include "Tag.hpp" #include "Revocation.hpp" +#include "Trace.hpp" namespace ZeroTier { @@ -63,11 +64,12 @@ bool IncomingPacket::tryDecode(const RuntimeEnvironment *RR,void *tPtr) // If this is marked as a packet via a trusted path, check source address and path ID. // Obviously if no trusted paths are configured this always returns false and such // packets are dropped on the floor. - if (RR->topology->shouldInboundPathBeTrusted(_path->address(),trustedPathId())) { + const uint64_t tpid = trustedPathId(); + if (RR->topology->shouldInboundPathBeTrusted(_path->address(),tpid)) { + RR->t->incomingPacketTrustedPath(_path,packetId(),sourceAddress,tpid,true); trusted = true; - TRACE("TRUSTED PATH packet approved from %s(%s), trusted path ID %llx",sourceAddress.toString().c_str(),_path->address().toString().c_str(),trustedPathId()); } else { - TRACE("dropped packet from %s(%s), cipher set to trusted path mode but path %llx@%s is not trusted!",sourceAddress.toString().c_str(),_path->address().toString().c_str(),trustedPathId(),_path->address().toString().c_str()); + RR->t->incomingPacketTrustedPath(_path,packetId(),sourceAddress,tpid,false); return true; } } else if ((c == ZT_PROTO_CIPHER_SUITE__C25519_POLY1305_NONE)&&(verb() == Packet::VERB_HELLO)) { @@ -80,19 +82,18 @@ bool IncomingPacket::tryDecode(const RuntimeEnvironment *RR,void *tPtr) if (!trusted) { if (!dearmor(peer->key())) { //fprintf(stderr,"dropped packet from %s(%s), MAC authentication failed (size: %u)" ZT_EOL_S,sourceAddress.toString().c_str(),_path->address().toString().c_str(),size()); - TRACE("dropped packet from %s(%s), MAC authentication failed (size: %u)",sourceAddress.toString().c_str(),_path->address().toString().c_str(),size()); + RR->t->incomingPacketMessageAuthenticationFailure(_path,packetId(),sourceAddress); return true; } } if (!uncompress()) { //fprintf(stderr,"dropped packet from %s(%s), compressed data invalid (size %u, verb may be %u)" ZT_EOL_S,sourceAddress.toString().c_str(),_path->address().toString().c_str(),size(),(unsigned int)verb()); - TRACE("dropped packet from %s(%s), compressed data invalid (size %u, verb may be %u)",sourceAddress.toString().c_str(),_path->address().toString().c_str(),size(),(unsigned int)verb()); + RR->t->incomingPacketInvalid(_path,packetId(),sourceAddress,Packet::VERB_NOP,"LZ4 decompression failed"); return true; } const Packet::Verb v = verb(); - //TRACE("<< %s from %s(%s)",Packet::verbString(v),sourceAddress.toString().c_str(),_path->address().toString().c_str()); switch(v) { //case Packet::VERB_NOP: default: // ignore unknown verbs, but if they pass auth check they are "received" @@ -121,9 +122,7 @@ bool IncomingPacket::tryDecode(const RuntimeEnvironment *RR,void *tPtr) return false; } } catch ( ... ) { - // Exceptions are more informatively caught in _do...() handlers but - // this outer try/catch will catch anything else odd. - TRACE("dropped ??? from %s(%s): unexpected exception in tryDecode()",sourceAddress.toString().c_str(),_path->address().toString().c_str()); + RR->t->incomingPacketInvalid(_path,packetId(),sourceAddress,Packet::VERB_NOP,"unexpected exception in tryDecode() (outer)"); return true; } } @@ -135,8 +134,6 @@ bool IncomingPacket::_doERROR(const RuntimeEnvironment *RR,void *tPtr,const Shar const uint64_t inRePacketId = at<uint64_t>(ZT_PROTO_VERB_ERROR_IDX_IN_RE_PACKET_ID); const Packet::ErrorCode errorCode = (Packet::ErrorCode)(*this)[ZT_PROTO_VERB_ERROR_IDX_ERROR_CODE]; - //TRACE("ERROR %s from %s(%s) in-re %s",Packet::errorString(errorCode),peer->address().toString().c_str(),_path->address().toString().c_str(),Packet::verbString(inReVerb)); - /* Security note: we do not gate doERROR() with expectingReplyTo() to * avoid having to log every outgoing packet ID. Instead we put the * logic to determine whether we should consider an ERROR in each @@ -192,7 +189,6 @@ bool IncomingPacket::_doERROR(const RuntimeEnvironment *RR,void *tPtr,const Shar const SharedPtr<Network> network(RR->node->network(at<uint64_t>(ZT_PROTO_VERB_ERROR_IDX_PAYLOAD))); if ((network)&&(network->gate(tPtr,peer))) { const MulticastGroup mg(MAC(field(ZT_PROTO_VERB_ERROR_IDX_PAYLOAD + 8,6),6),at<uint32_t>(ZT_PROTO_VERB_ERROR_IDX_PAYLOAD + 14)); - TRACE("%.16llx: peer %s unsubscrubed from multicast group %s",network->id(),peer->address().toString().c_str(),mg.toString().c_str()); RR->mc->remove(network->id(),mg,peer->address()); } } break; @@ -202,7 +198,7 @@ bool IncomingPacket::_doERROR(const RuntimeEnvironment *RR,void *tPtr,const Shar peer->received(tPtr,_path,hops(),packetId(),Packet::VERB_ERROR,inRePacketId,inReVerb,false); } catch ( ... ) { - TRACE("dropped ERROR from %s(%s): unexpected exception",peer->address().toString().c_str(),_path->address().toString().c_str()); + RR->t->incomingPacketInvalid(_path,packetId(),source(),Packet::VERB_ERROR,"unexpected exception"); } return true; } @@ -223,11 +219,11 @@ bool IncomingPacket::_doHELLO(const RuntimeEnvironment *RR,void *tPtr,const bool unsigned int ptr = ZT_PROTO_VERB_HELLO_IDX_IDENTITY + id.deserialize(*this,ZT_PROTO_VERB_HELLO_IDX_IDENTITY); if (protoVersion < ZT_PROTO_VERSION_MIN) { - TRACE("dropped HELLO from %s(%s): protocol version too old",id.address().toString().c_str(),_path->address().toString().c_str()); + RR->t->incomingPacketDroppedHELLO(_path,pid,fromAddress,"protocol version too old"); return true; } if (fromAddress != id.address()) { - TRACE("dropped HELLO from %s(%s): identity does not match packet source address",fromAddress.toString().c_str(),_path->address().toString().c_str()); + RR->t->incomingPacketDroppedHELLO(_path,pid,fromAddress,"identity/address mismatch"); return true; } @@ -245,7 +241,7 @@ bool IncomingPacket::_doHELLO(const RuntimeEnvironment *RR,void *tPtr,const bool uint8_t key[ZT_PEER_SECRET_KEY_LENGTH]; if (RR->identity.agree(id,key,ZT_PEER_SECRET_KEY_LENGTH)) { if (dearmor(key)) { // ensure packet is authentic, otherwise drop - TRACE("rejected HELLO from %s(%s): address already claimed",id.address().toString().c_str(),_path->address().toString().c_str()); + RR->t->incomingPacketDroppedHELLO(_path,pid,fromAddress,"address collision"); Packet outp(id.address(),RR->identity.address(),Packet::VERB_ERROR); outp.append((uint8_t)Packet::VERB_HELLO); outp.append((uint64_t)pid); @@ -253,10 +249,10 @@ bool IncomingPacket::_doHELLO(const RuntimeEnvironment *RR,void *tPtr,const bool outp.armor(key,true,_path->nextOutgoingCounter()); _path->send(RR,tPtr,outp.data(),outp.size(),RR->node->now()); } else { - TRACE("rejected HELLO from %s(%s): packet failed authentication",id.address().toString().c_str(),_path->address().toString().c_str()); + RR->t->incomingPacketMessageAuthenticationFailure(_path,pid,fromAddress); } } else { - TRACE("rejected HELLO from %s(%s): key agreement failed",id.address().toString().c_str(),_path->address().toString().c_str()); + RR->t->incomingPacketMessageAuthenticationFailure(_path,pid,fromAddress); } return true; @@ -264,7 +260,7 @@ bool IncomingPacket::_doHELLO(const RuntimeEnvironment *RR,void *tPtr,const bool // Identity is the same as the one we already have -- check packet integrity if (!dearmor(peer->key())) { - TRACE("rejected HELLO from %s(%s): packet failed authentication",id.address().toString().c_str(),_path->address().toString().c_str()); + RR->t->incomingPacketMessageAuthenticationFailure(_path,pid,fromAddress); return true; } @@ -276,24 +272,26 @@ bool IncomingPacket::_doHELLO(const RuntimeEnvironment *RR,void *tPtr,const bool // Sanity check: this basically can't happen if (alreadyAuthenticated) { - TRACE("dropped HELLO from %s(%s): somehow already authenticated with unknown peer?",id.address().toString().c_str(),_path->address().toString().c_str()); + RR->t->incomingPacketDroppedHELLO(_path,pid,fromAddress,"illegal alreadyAuthenticated state"); return true; } // Check rate limits - if (!RR->node->rateGateIdentityVerification(now,_path->address())) + if (!RR->node->rateGateIdentityVerification(now,_path->address())) { + RR->t->incomingPacketDroppedHELLO(_path,pid,fromAddress,"rate limit exceeded"); return true; + } // Check packet integrity and MAC (this is faster than locallyValidate() so do it first to filter out total crap) SharedPtr<Peer> newPeer(new Peer(RR,RR->identity,id)); if (!dearmor(newPeer->key())) { - TRACE("rejected HELLO from %s(%s): packet failed authentication",id.address().toString().c_str(),_path->address().toString().c_str()); + RR->t->incomingPacketMessageAuthenticationFailure(_path,pid,fromAddress); return true; } // Check that identity's address is valid as per the derivation function if (!id.locallyValidate()) { - TRACE("dropped HELLO from %s(%s): identity invalid",id.address().toString().c_str(),_path->address().toString().c_str()); + RR->t->incomingPacketDroppedHELLO(_path,pid,fromAddress,"invalid identity"); return true; } @@ -418,7 +416,7 @@ bool IncomingPacket::_doHELLO(const RuntimeEnvironment *RR,void *tPtr,const bool peer->setRemoteVersion(protoVersion,vMajor,vMinor,vRevision); // important for this to go first so received() knows the version peer->received(tPtr,_path,hops(),pid,Packet::VERB_HELLO,0,Packet::VERB_NOP,false); } catch ( ... ) { - TRACE("dropped HELLO from %s(%s): unexpected exception",source().toString().c_str(),_path->address().toString().c_str()); + RR->t->incomingPacketInvalid(_path,packetId(),source(),Packet::VERB_HELLO,"unexpected exception"); } return true; } @@ -429,12 +427,8 @@ bool IncomingPacket::_doOK(const RuntimeEnvironment *RR,void *tPtr,const SharedP const Packet::Verb inReVerb = (Packet::Verb)(*this)[ZT_PROTO_VERB_OK_IDX_IN_RE_VERB]; const uint64_t inRePacketId = at<uint64_t>(ZT_PROTO_VERB_OK_IDX_IN_RE_PACKET_ID); - if (!RR->node->expectingReplyTo(inRePacketId)) { - TRACE("%s(%s): OK(%s) DROPPED: not expecting reply to %.16llx",peer->address().toString().c_str(),_path->address().toString().c_str(),Packet::verbString(inReVerb),packetId()); + if (!RR->node->expectingReplyTo(inRePacketId)) return true; - } - - //TRACE("%s(%s): OK(%s)",peer->address().toString().c_str(),_path->address().toString().c_str(),Packet::verbString(inReVerb)); switch(inReVerb) { @@ -447,11 +441,8 @@ bool IncomingPacket::_doOK(const RuntimeEnvironment *RR,void *tPtr,const SharedP const unsigned int vMajor = (*this)[ZT_PROTO_VERB_HELLO__OK__IDX_MAJOR_VERSION]; const unsigned int vMinor = (*this)[ZT_PROTO_VERB_HELLO__OK__IDX_MINOR_VERSION]; const unsigned int vRevision = at<uint16_t>(ZT_PROTO_VERB_HELLO__OK__IDX_REVISION); - - if (vProto < ZT_PROTO_VERSION_MIN) { - TRACE("%s(%s): OK(HELLO) dropped, protocol version too old",source().toString().c_str(),_path->address().toString().c_str()); + if (vProto < ZT_PROTO_VERSION_MIN) return true; - } InetAddress externalSurfaceAddress; unsigned int ptr = ZT_PROTO_VERB_HELLO__OK__IDX_REVISION + 2; @@ -484,12 +475,6 @@ bool IncomingPacket::_doOK(const RuntimeEnvironment *RR,void *tPtr,const SharedP } else ptr += 2; } -#ifdef ZT_TRACE - const std::string tmp1(source().toString()); - const std::string tmp2(_path->address().toString()); - TRACE("%s(%s): OK(HELLO), version %u.%u.%u, latency %u",tmp1.c_str(),tmp2.c_str(),vMajor,vMinor,vRevision,latency); -#endif - if (!hops()) peer->addDirectLatencyMeasurment((unsigned int)latency); peer->setRemoteVersion(vProto,vMajor,vMinor,vRevision); @@ -516,7 +501,6 @@ bool IncomingPacket::_doOK(const RuntimeEnvironment *RR,void *tPtr,const SharedP const SharedPtr<Network> network(RR->node->network(nwid)); if (network) { const MulticastGroup mg(MAC(field(ZT_PROTO_VERB_MULTICAST_GATHER__OK__IDX_MAC,6),6),at<uint32_t>(ZT_PROTO_VERB_MULTICAST_GATHER__OK__IDX_ADI)); - //TRACE("%s(%s): OK(MULTICAST_GATHER) %.16llx/%s length %u",source().toString().c_str(),_path->address().toString().c_str(),nwid,mg.toString().c_str(),size()); const unsigned int count = at<uint16_t>(ZT_PROTO_VERB_MULTICAST_GATHER__OK__IDX_GATHER_RESULTS + 4); RR->mc->addMultiple(tPtr,RR->node->now(),nwid,mg,field(ZT_PROTO_VERB_MULTICAST_GATHER__OK__IDX_GATHER_RESULTS + 6,count * 5),count,at<uint32_t>(ZT_PROTO_VERB_MULTICAST_GATHER__OK__IDX_GATHER_RESULTS)); } @@ -527,8 +511,6 @@ bool IncomingPacket::_doOK(const RuntimeEnvironment *RR,void *tPtr,const SharedP const uint64_t nwid = at<uint64_t>(ZT_PROTO_VERB_MULTICAST_FRAME__OK__IDX_NETWORK_ID); const MulticastGroup mg(MAC(field(ZT_PROTO_VERB_MULTICAST_FRAME__OK__IDX_MAC,6),6),at<uint32_t>(ZT_PROTO_VERB_MULTICAST_FRAME__OK__IDX_ADI)); - //TRACE("%s(%s): OK(MULTICAST_FRAME) %.16llx/%s flags %.2x",peer->address().toString().c_str(),_path->address().toString().c_str(),nwid,mg.toString().c_str(),flags); - const SharedPtr<Network> network(RR->node->network(nwid)); if (network) { unsigned int offset = 0; @@ -555,7 +537,7 @@ bool IncomingPacket::_doOK(const RuntimeEnvironment *RR,void *tPtr,const SharedP peer->received(tPtr,_path,hops(),packetId(),Packet::VERB_OK,inRePacketId,inReVerb,false); } catch ( ... ) { - TRACE("dropped OK from %s(%s): unexpected exception",source().toString().c_str(),_path->address().toString().c_str()); + RR->t->incomingPacketInvalid(_path,packetId(),source(),Packet::VERB_OK,"unexpected exception"); } return true; } @@ -563,10 +545,8 @@ bool IncomingPacket::_doOK(const RuntimeEnvironment *RR,void *tPtr,const SharedP bool IncomingPacket::_doWHOIS(const RuntimeEnvironment *RR,void *tPtr,const SharedPtr<Peer> &peer) { try { - if ((!RR->topology->amRoot())&&(!peer->rateGateInboundWhoisRequest(RR->node->now()))) { - TRACE("dropped WHOIS from %s(%s): rate limit circuit breaker tripped",source().toString().c_str(),_path->address().toString().c_str()); + if ((!RR->topology->amRoot())&&(!peer->rateGateInboundWhoisRequest(RR->node->now()))) return true; - } Packet outp(peer->address(),RR->identity.address(),Packet::VERB_OK); outp.append((unsigned char)Packet::VERB_WHOIS); @@ -595,7 +575,7 @@ bool IncomingPacket::_doWHOIS(const RuntimeEnvironment *RR,void *tPtr,const Shar peer->received(tPtr,_path,hops(),packetId(),Packet::VERB_WHOIS,0,Packet::VERB_NOP,false); } catch ( ... ) { - TRACE("dropped WHOIS from %s(%s): unexpected exception",source().toString().c_str(),_path->address().toString().c_str()); + RR->t->incomingPacketInvalid(_path,packetId(),source(),Packet::VERB_WHOIS,"unexpected exception"); } return true; } @@ -603,9 +583,7 @@ bool IncomingPacket::_doWHOIS(const RuntimeEnvironment *RR,void *tPtr,const Shar bool IncomingPacket::_doRENDEZVOUS(const RuntimeEnvironment *RR,void *tPtr,const SharedPtr<Peer> &peer) { try { - if (!RR->topology->isUpstream(peer->identity())) { - TRACE("RENDEZVOUS from %s ignored since source is not upstream",peer->address().toString().c_str()); - } else { + if (RR->topology->isUpstream(peer->identity())) { const Address with(field(ZT_PROTO_VERB_RENDEZVOUS_IDX_ZTADDRESS,ZT_ADDRESS_LENGTH),ZT_ADDRESS_LENGTH); const SharedPtr<Peer> rendezvousWith(RR->topology->getPeer(tPtr,with)); if (rendezvousWith) { @@ -614,22 +592,16 @@ bool IncomingPacket::_doRENDEZVOUS(const RuntimeEnvironment *RR,void *tPtr,const if ((port > 0)&&((addrlen == 4)||(addrlen == 16))) { const InetAddress atAddr(field(ZT_PROTO_VERB_RENDEZVOUS_IDX_ADDRESS,addrlen),addrlen,port); if (RR->node->shouldUsePathForZeroTierTraffic(tPtr,with,_path->localSocket(),atAddr)) { - RR->node->putPacket(tPtr,_path->localSocket(),atAddr,"ABRE",4,2); // send low-TTL junk packet to 'open' local NAT(s) and stateful firewalls + const uint64_t junk = RR->node->prng(); + RR->node->putPacket(tPtr,_path->localSocket(),atAddr,&junk,4,2); // send low-TTL junk packet to 'open' local NAT(s) and stateful firewalls rendezvousWith->attemptToContactAt(tPtr,_path->localSocket(),atAddr,RR->node->now(),false,0); - TRACE("RENDEZVOUS from %s says %s might be at %s, sent verification attempt",peer->address().toString().c_str(),with.toString().c_str(),atAddr.toString().c_str()); - } else { - TRACE("RENDEZVOUS from %s says %s might be at %s, ignoring since path is not suitable",peer->address().toString().c_str(),with.toString().c_str(),atAddr.toString().c_str()); } - } else { - TRACE("dropped corrupt RENDEZVOUS from %s(%s) (bad address or port)",peer->address().toString().c_str(),_path->address().toString().c_str()); } - } else { - TRACE("ignored RENDEZVOUS from %s(%s) to meet unknown peer %s",peer->address().toString().c_str(),_path->address().toString().c_str(),with.toString().c_str()); } } peer->received(tPtr,_path,hops(),packetId(),Packet::VERB_RENDEZVOUS,0,Packet::VERB_NOP,false); } catch ( ... ) { - TRACE("dropped RENDEZVOUS from %s(%s): unexpected exception",peer->address().toString().c_str(),_path->address().toString().c_str()); + RR->t->incomingPacketInvalid(_path,packetId(),source(),Packet::VERB_RENDEZVOUS,"unexpected exception"); } return true; } @@ -652,16 +624,15 @@ bool IncomingPacket::_doFRAME(const RuntimeEnvironment *RR,void *tPtr,const Shar RR->node->putFrame(tPtr,nwid,network->userPtr(),sourceMac,network->mac(),etherType,0,(const void *)frameData,frameLen); } } else { - TRACE("dropped FRAME from %s(%s): not a member of private network %.16llx",peer->address().toString().c_str(),_path->address().toString().c_str(),(unsigned long long)network->id()); _sendErrorNeedCredentials(RR,tPtr,peer,nwid); + RR->t->networkAccessDenied(network,_path,packetId(),size(),peer->address(),Packet::VERB_FRAME,true); } } else { - TRACE("dropped FRAME from %s(%s): we are not a member of network %.16llx",source().toString().c_str(),_path->address().toString().c_str(),at<uint64_t>(ZT_PROTO_VERB_FRAME_IDX_NETWORK_ID)); _sendErrorNeedCredentials(RR,tPtr,peer,nwid); } peer->received(tPtr,_path,hops(),packetId(),Packet::VERB_FRAME,0,Packet::VERB_NOP,trustEstablished); } catch ( ... ) { - TRACE("dropped FRAME from %s(%s): unexpected exception",source().toString().c_str(),_path->address().toString().c_str()); + RR->t->incomingPacketInvalid(_path,packetId(),source(),Packet::VERB_FRAME,"unexpected exception"); } return true; } @@ -683,7 +654,7 @@ bool IncomingPacket::_doEXT_FRAME(const RuntimeEnvironment *RR,void *tPtr,const } if (!network->gate(tPtr,peer)) { - TRACE("dropped EXT_FRAME from %s(%s): not a member of private network %.16llx",peer->address().toString().c_str(),_path->address().toString().c_str(),network->id()); + RR->t->networkAccessDenied(network,_path,packetId(),size(),peer->address(),Packet::VERB_EXT_FRAME,true); _sendErrorNeedCredentials(RR,tPtr,peer,nwid); peer->received(tPtr,_path,hops(),packetId(),Packet::VERB_EXT_FRAME,0,Packet::VERB_NOP,false); return true; @@ -696,8 +667,7 @@ bool IncomingPacket::_doEXT_FRAME(const RuntimeEnvironment *RR,void *tPtr,const const unsigned int frameLen = size() - (comLen + ZT_PROTO_VERB_EXT_FRAME_IDX_PAYLOAD); const uint8_t *const frameData = (const uint8_t *)field(comLen + ZT_PROTO_VERB_EXT_FRAME_IDX_PAYLOAD,frameLen); - if ((!from)||(from.isMulticast())||(from == network->mac())) { - TRACE("dropped EXT_FRAME from %s@%s(%s) to %s: invalid source MAC %s",from.toString().c_str(),peer->address().toString().c_str(),_path->address().toString().c_str(),to.toString().c_str(),from.toString().c_str()); + if ((!from)||(from == network->mac())) { peer->received(tPtr,_path,hops(),packetId(),Packet::VERB_EXT_FRAME,0,Packet::VERB_NOP,true); // trustEstablished because COM is okay return true; } @@ -708,19 +678,19 @@ bool IncomingPacket::_doEXT_FRAME(const RuntimeEnvironment *RR,void *tPtr,const if (network->config().permitsBridging(peer->address())) { network->learnBridgeRoute(from,peer->address()); } else { - TRACE("dropped EXT_FRAME from %s@%s(%s) to %s: sender not allowed to bridge into %.16llx",from.toString().c_str(),peer->address().toString().c_str(),_path->address().toString().c_str(),to.toString().c_str(),network->id()); + RR->t->networkFrameDropped(network,_path,packetId(),size(),peer->address(),Packet::VERB_EXT_FRAME,from,to); peer->received(tPtr,_path,hops(),packetId(),Packet::VERB_EXT_FRAME,0,Packet::VERB_NOP,true); // trustEstablished because COM is okay return true; } } else if (to != network->mac()) { if (to.isMulticast()) { if (network->config().multicastLimit == 0) { - TRACE("dropped EXT_FRAME from %s@%s(%s) to %s: network %.16llx does not allow multicast",from.toString().c_str(),peer->address().toString().c_str(),_path->address().toString().c_str(),to.toString().c_str(),network->id()); + RR->t->networkFrameDropped(network,_path,packetId(),size(),peer->address(),Packet::VERB_EXT_FRAME,from,to); peer->received(tPtr,_path,hops(),packetId(),Packet::VERB_EXT_FRAME,0,Packet::VERB_NOP,true); // trustEstablished because COM is okay return true; } } else if (!network->config().permitsBridging(RR->identity.address())) { - TRACE("dropped EXT_FRAME from %s@%s(%s) to %s: I cannot bridge to %.16llx or bridging disabled on network",from.toString().c_str(),peer->address().toString().c_str(),_path->address().toString().c_str(),to.toString().c_str(),network->id()); + RR->t->networkFrameDropped(network,_path,packetId(),size(),peer->address(),Packet::VERB_EXT_FRAME,from,to); peer->received(tPtr,_path,hops(),packetId(),Packet::VERB_EXT_FRAME,0,Packet::VERB_NOP,true); // trustEstablished because COM is okay return true; } @@ -743,12 +713,10 @@ bool IncomingPacket::_doEXT_FRAME(const RuntimeEnvironment *RR,void *tPtr,const peer->received(tPtr,_path,hops(),packetId(),Packet::VERB_EXT_FRAME,0,Packet::VERB_NOP,true); } else { - TRACE("dropped EXT_FRAME from %s(%s): we are not connected to network %.16llx",source().toString().c_str(),_path->address().toString().c_str(),at<uint64_t>(ZT_PROTO_VERB_FRAME_IDX_NETWORK_ID)); - _sendErrorNeedCredentials(RR,tPtr,peer,nwid); peer->received(tPtr,_path,hops(),packetId(),Packet::VERB_EXT_FRAME,0,Packet::VERB_NOP,false); } } catch ( ... ) { - TRACE("dropped EXT_FRAME from %s(%s): unexpected exception",source().toString().c_str(),_path->address().toString().c_str()); + RR->t->incomingPacketInvalid(_path,packetId(),source(),Packet::VERB_EXT_FRAME,"unexpected exception"); } return true; } @@ -756,10 +724,8 @@ bool IncomingPacket::_doEXT_FRAME(const RuntimeEnvironment *RR,void *tPtr,const bool IncomingPacket::_doECHO(const RuntimeEnvironment *RR,void *tPtr,const SharedPtr<Peer> &peer) { try { - if (!peer->rateGateEchoRequest(RR->node->now())) { - TRACE("dropped ECHO from %s(%s): rate limit circuit breaker tripped",source().toString().c_str(),_path->address().toString().c_str()); + if (!peer->rateGateEchoRequest(RR->node->now())) return true; - } const uint64_t pid = packetId(); Packet outp(peer->address(),RR->identity.address(),Packet::VERB_OK); @@ -772,7 +738,7 @@ bool IncomingPacket::_doECHO(const RuntimeEnvironment *RR,void *tPtr,const Share peer->received(tPtr,_path,hops(),pid,Packet::VERB_ECHO,0,Packet::VERB_NOP,false); } catch ( ... ) { - TRACE("dropped ECHO from %s(%s): unexpected exception",source().toString().c_str(),_path->address().toString().c_str()); + RR->t->incomingPacketInvalid(_path,packetId(),source(),Packet::VERB_ECHO,"unexpected exception"); } return true; } @@ -820,7 +786,7 @@ bool IncomingPacket::_doMULTICAST_LIKE(const RuntimeEnvironment *RR,void *tPtr,c peer->received(tPtr,_path,hops(),packetId(),Packet::VERB_MULTICAST_LIKE,0,Packet::VERB_NOP,trustEstablished); } catch ( ... ) { - TRACE("dropped MULTICAST_LIKE from %s(%s): unexpected exception",source().toString().c_str(),_path->address().toString().c_str()); + RR->t->incomingPacketInvalid(_path,packetId(),source(),Packet::VERB_MULTICAST_LIKE,"unexpected exception"); } return true; } @@ -828,10 +794,8 @@ bool IncomingPacket::_doMULTICAST_LIKE(const RuntimeEnvironment *RR,void *tPtr,c bool IncomingPacket::_doNETWORK_CREDENTIALS(const RuntimeEnvironment *RR,void *tPtr,const SharedPtr<Peer> &peer) { try { - if (!peer->rateGateCredentialsReceived(RR->node->now())) { - TRACE("dropped NETWORK_CREDENTIALS from %s(%s): rate limit circuit breaker tripped",source().toString().c_str(),_path->address().toString().c_str()); + if (!peer->rateGateCredentialsReceived(RR->node->now())) return true; - } CertificateOfMembership com; Capability cap; @@ -942,12 +906,8 @@ bool IncomingPacket::_doNETWORK_CREDENTIALS(const RuntimeEnvironment *RR,void *t } peer->received(tPtr,_path,hops(),packetId(),Packet::VERB_NETWORK_CREDENTIALS,0,Packet::VERB_NOP,trustEstablished); - } catch (std::exception &exc) { - //fprintf(stderr,"dropped NETWORK_CREDENTIALS from %s(%s): %s" ZT_EOL_S,source().toString().c_str(),_path->address().toString().c_str(),exc.what()); - TRACE("dropped NETWORK_CREDENTIALS from %s(%s): %s",source().toString().c_str(),_path->address().toString().c_str(),exc.what()); } catch ( ... ) { - //fprintf(stderr,"dropped NETWORK_CREDENTIALS from %s(%s): unknown exception" ZT_EOL_S,source().toString().c_str(),_path->address().toString().c_str()); - TRACE("dropped NETWORK_CREDENTIALS from %s(%s): unknown exception",source().toString().c_str(),_path->address().toString().c_str()); + RR->t->incomingPacketInvalid(_path,packetId(),source(),Packet::VERB_NETWORK_CREDENTIALS,"unexpected exception"); } return true; } @@ -975,12 +935,8 @@ bool IncomingPacket::_doNETWORK_CONFIG_REQUEST(const RuntimeEnvironment *RR,void } peer->received(tPtr,_path,hopCount,requestPacketId,Packet::VERB_NETWORK_CONFIG_REQUEST,0,Packet::VERB_NOP,false); - } catch (std::exception &exc) { - //fprintf(stderr,"dropped NETWORK_CONFIG_REQUEST from %s(%s): %s" ZT_EOL_S,source().toString().c_str(),_path->address().toString().c_str(),exc.what()); - TRACE("dropped NETWORK_CONFIG_REQUEST from %s(%s): %s",source().toString().c_str(),_path->address().toString().c_str(),exc.what()); } catch ( ... ) { - //fprintf(stderr,"dropped NETWORK_CONFIG_REQUEST from %s(%s): unknown exception" ZT_EOL_S,source().toString().c_str(),_path->address().toString().c_str()); - TRACE("dropped NETWORK_CONFIG_REQUEST from %s(%s): unknown exception",source().toString().c_str(),_path->address().toString().c_str()); + RR->t->incomingPacketInvalid(_path,packetId(),source(),Packet::VERB_NETWORK_CONFIG_REQUEST,"unexpected exception"); } return true; } @@ -1003,7 +959,7 @@ bool IncomingPacket::_doNETWORK_CONFIG(const RuntimeEnvironment *RR,void *tPtr,c } peer->received(tPtr,_path,hops(),packetId(),Packet::VERB_NETWORK_CONFIG,0,Packet::VERB_NOP,false); } catch ( ... ) { - TRACE("dropped NETWORK_CONFIG_REFRESH from %s(%s): unexpected exception",source().toString().c_str(),_path->address().toString().c_str()); + RR->t->incomingPacketInvalid(_path,packetId(),source(),Packet::VERB_NETWORK_CONFIG,"unexpected exception"); } return true; } @@ -1016,8 +972,6 @@ bool IncomingPacket::_doMULTICAST_GATHER(const RuntimeEnvironment *RR,void *tPtr const MulticastGroup mg(MAC(field(ZT_PROTO_VERB_MULTICAST_GATHER_IDX_MAC,6),6),at<uint32_t>(ZT_PROTO_VERB_MULTICAST_GATHER_IDX_ADI)); const unsigned int gatherLimit = at<uint32_t>(ZT_PROTO_VERB_MULTICAST_GATHER_IDX_GATHER_LIMIT); - //TRACE("<<MC %s(%s) GATHER up to %u in %.16llx/%s",source().toString().c_str(),_path->address().toString().c_str(),gatherLimit,nwid,mg.toString().c_str()); - const SharedPtr<Network> network(RR->node->network(nwid)); if ((flags & 0x01) != 0) { @@ -1029,9 +983,7 @@ bool IncomingPacket::_doMULTICAST_GATHER(const RuntimeEnvironment *RR,void *tPtr network->addCredential(tPtr,com); else RR->mc->addCredential(tPtr,com,false); } - } catch ( ... ) { - TRACE("MULTICAST_GATHER from %s(%s): discarded invalid COM",peer->address().toString().c_str(),_path->address().toString().c_str()); - } + } catch ( ... ) {} // discard invalid COMs } const bool trustEstablished = ((network)&&(network->gate(tPtr,peer))); @@ -1053,7 +1005,7 @@ bool IncomingPacket::_doMULTICAST_GATHER(const RuntimeEnvironment *RR,void *tPtr peer->received(tPtr,_path,hops(),packetId(),Packet::VERB_MULTICAST_GATHER,0,Packet::VERB_NOP,trustEstablished); } catch ( ... ) { - TRACE("dropped MULTICAST_GATHER from %s(%s): unexpected exception",peer->address().toString().c_str(),_path->address().toString().c_str()); + RR->t->incomingPacketInvalid(_path,packetId(),source(),Packet::VERB_MULTICAST_GATHER,"unexpected exception"); } return true; } @@ -1078,18 +1030,12 @@ bool IncomingPacket::_doMULTICAST_FRAME(const RuntimeEnvironment *RR,void *tPtr, } if (!network->gate(tPtr,peer)) { - TRACE("dropped MULTICAST_FRAME from %s(%s): not a member of private network %.16llx",peer->address().toString().c_str(),_path->address().toString().c_str(),(unsigned long long)network->id()); + RR->t->networkAccessDenied(network,_path,packetId(),size(),peer->address(),Packet::VERB_MULTICAST_FRAME,true); _sendErrorNeedCredentials(RR,tPtr,peer,nwid); peer->received(tPtr,_path,hops(),packetId(),Packet::VERB_MULTICAST_FRAME,0,Packet::VERB_NOP,false); return true; } - if (network->config().multicastLimit == 0) { - TRACE("dropped MULTICAST_FRAME from %s(%s): network %.16llx does not allow multicast",peer->address().toString().c_str(),_path->address().toString().c_str(),(unsigned long long)network->id()); - peer->received(tPtr,_path,hops(),packetId(),Packet::VERB_MULTICAST_FRAME,0,Packet::VERB_NOP,false); - return true; - } - unsigned int gatherLimit = 0; if ((flags & 0x02) != 0) { gatherLimit = at<uint32_t>(offset + ZT_PROTO_VERB_MULTICAST_FRAME_IDX_GATHER_LIMIT); @@ -1108,16 +1054,20 @@ bool IncomingPacket::_doMULTICAST_FRAME(const RuntimeEnvironment *RR,void *tPtr, const unsigned int etherType = at<uint16_t>(offset + ZT_PROTO_VERB_MULTICAST_FRAME_IDX_ETHERTYPE); const unsigned int frameLen = size() - (offset + ZT_PROTO_VERB_MULTICAST_FRAME_IDX_FRAME); - //TRACE("<<MC FRAME %.16llx/%s from %s@%s flags %.2x length %u",nwid,to.toString().c_str(),from.toString().c_str(),peer->address().toString().c_str(),flags,frameLen); + if (network->config().multicastLimit == 0) { + RR->t->networkFrameDropped(network,_path,packetId(),size(),peer->address(),Packet::VERB_MULTICAST_FRAME,from,to.mac()); + peer->received(tPtr,_path,hops(),packetId(),Packet::VERB_MULTICAST_FRAME,0,Packet::VERB_NOP,false); + return true; + } if ((frameLen > 0)&&(frameLen <= ZT_MAX_MTU)) { if (!to.mac().isMulticast()) { - TRACE("dropped MULTICAST_FRAME from %s@%s(%s) to %s: destination is unicast, must use FRAME or EXT_FRAME",from.toString().c_str(),peer->address().toString().c_str(),_path->address().toString().c_str(),to.toString().c_str()); + RR->t->incomingPacketInvalid(_path,packetId(),source(),Packet::VERB_MULTICAST_FRAME,"destination not multicast"); peer->received(tPtr,_path,hops(),packetId(),Packet::VERB_MULTICAST_FRAME,0,Packet::VERB_NOP,true); // trustEstablished because COM is okay return true; } if ((!from)||(from.isMulticast())||(from == network->mac())) { - TRACE("dropped MULTICAST_FRAME from %s@%s(%s) to %s: invalid source MAC",from.toString().c_str(),peer->address().toString().c_str(),_path->address().toString().c_str(),to.toString().c_str()); + RR->t->incomingPacketInvalid(_path,packetId(),source(),Packet::VERB_MULTICAST_FRAME,"invalid source MAC"); peer->received(tPtr,_path,hops(),packetId(),Packet::VERB_MULTICAST_FRAME,0,Packet::VERB_NOP,true); // trustEstablished because COM is okay return true; } @@ -1126,16 +1076,15 @@ bool IncomingPacket::_doMULTICAST_FRAME(const RuntimeEnvironment *RR,void *tPtr, if (network->config().permitsBridging(peer->address())) { network->learnBridgeRoute(from,peer->address()); } else { - TRACE("dropped MULTICAST_FRAME from %s@%s(%s) to %s: sender not allowed to bridge into %.16llx",from.toString().c_str(),peer->address().toString().c_str(),_path->address().toString().c_str(),to.toString().c_str(),network->id()); + RR->t->networkFrameDropped(network,_path,packetId(),size(),peer->address(),Packet::VERB_MULTICAST_FRAME,from,to.mac()); peer->received(tPtr,_path,hops(),packetId(),Packet::VERB_MULTICAST_FRAME,0,Packet::VERB_NOP,true); // trustEstablished because COM is okay return true; } } const uint8_t *const frameData = (const uint8_t *)field(offset + ZT_PROTO_VERB_MULTICAST_FRAME_IDX_FRAME,frameLen); - if (network->filterIncomingPacket(tPtr,peer,RR->identity.address(),from,to.mac(),frameData,frameLen,etherType,0) > 0) { + if (network->filterIncomingPacket(tPtr,peer,RR->identity.address(),from,to.mac(),frameData,frameLen,etherType,0) > 0) RR->node->putFrame(tPtr,nwid,network->userPtr(),from,to.mac(),etherType,0,(const void *)frameData,frameLen); - } } if (gatherLimit) { @@ -1158,7 +1107,7 @@ bool IncomingPacket::_doMULTICAST_FRAME(const RuntimeEnvironment *RR,void *tPtr, peer->received(tPtr,_path,hops(),packetId(),Packet::VERB_MULTICAST_FRAME,0,Packet::VERB_NOP,false); } } catch ( ... ) { - TRACE("dropped MULTICAST_FRAME from %s(%s): unexpected exception",source().toString().c_str(),_path->address().toString().c_str()); + RR->t->incomingPacketInvalid(_path,packetId(),source(),Packet::VERB_MULTICAST_FRAME,"unexpected exception"); } return true; } @@ -1170,7 +1119,6 @@ bool IncomingPacket::_doPUSH_DIRECT_PATHS(const RuntimeEnvironment *RR,void *tPt // First, subject this to a rate limit if (!peer->rateGatePushDirectPaths(now)) { - //TRACE("dropped PUSH_DIRECT_PATHS from %s(%s): circuit breaker tripped",source().toString().c_str(),_path->address().toString().c_str()); peer->received(tPtr,_path,hops(),packetId(),Packet::VERB_PUSH_DIRECT_PATHS,0,Packet::VERB_NOP,false); return true; } @@ -1202,10 +1150,7 @@ bool IncomingPacket::_doPUSH_DIRECT_PATHS(const RuntimeEnvironment *RR,void *tPt if ((flags & ZT_PUSH_DIRECT_PATHS_FLAG_CLUSTER_REDIRECT) != 0) { peer->redirect(tPtr,_path->localSocket(),a,now); } else if (++countPerScope[(int)a.ipScope()][0] <= ZT_PUSH_DIRECT_PATHS_MAX_PER_SCOPE_AND_FAMILY) { - TRACE("attempting to contact %s at pushed direct path %s",peer->address().toString().c_str(),a.toString().c_str()); peer->attemptToContactAt(tPtr,InetAddress(),a,now,false,0); - } else { - //TRACE("ignoring contact for %s at %s -- too many per scope",peer->address().toString().c_str(),a.toString().c_str()); } } } break; @@ -1219,10 +1164,7 @@ bool IncomingPacket::_doPUSH_DIRECT_PATHS(const RuntimeEnvironment *RR,void *tPt if ((flags & ZT_PUSH_DIRECT_PATHS_FLAG_CLUSTER_REDIRECT) != 0) { peer->redirect(tPtr,_path->localSocket(),a,now); } else if (++countPerScope[(int)a.ipScope()][1] <= ZT_PUSH_DIRECT_PATHS_MAX_PER_SCOPE_AND_FAMILY) { - TRACE("attempting to contact %s at pushed direct path %s",peer->address().toString().c_str(),a.toString().c_str()); peer->attemptToContactAt(tPtr,InetAddress(),a,now,false,0); - } else { - //TRACE("ignoring contact for %s at %s -- too many per scope",peer->address().toString().c_str(),a.toString().c_str()); } } } break; @@ -1232,7 +1174,7 @@ bool IncomingPacket::_doPUSH_DIRECT_PATHS(const RuntimeEnvironment *RR,void *tPt peer->received(tPtr,_path,hops(),packetId(),Packet::VERB_PUSH_DIRECT_PATHS,0,Packet::VERB_NOP,false); } catch ( ... ) { - TRACE("dropped PUSH_DIRECT_PATHS from %s(%s): unexpected exception",source().toString().c_str(),_path->address().toString().c_str()); + RR->t->incomingPacketInvalid(_path,packetId(),source(),Packet::VERB_PUSH_DIRECT_PATHS,"unexpected exception"); } return true; } @@ -1250,7 +1192,7 @@ bool IncomingPacket::_doUSER_MESSAGE(const RuntimeEnvironment *RR,void *tPtr,con } peer->received(tPtr,_path,hops(),packetId(),Packet::VERB_USER_MESSAGE,0,Packet::VERB_NOP,false); } catch ( ... ) { - TRACE("dropped USER_MESSAGE from %s(%s): unexpected exception",source().toString().c_str(),_path->address().toString().c_str()); + RR->t->incomingPacketInvalid(_path,packetId(),source(),Packet::VERB_USER_MESSAGE,"unexpected exception"); } return true; } diff --git a/node/Membership.cpp b/node/Membership.cpp index 466f9021..be6ea6a5 100644 --- a/node/Membership.cpp +++ b/node/Membership.cpp @@ -33,6 +33,7 @@ #include "Switch.hpp" #include "Packet.hpp" #include "Node.hpp" +#include "Trace.hpp" #define ZT_CREDENTIAL_PUSH_EVERY (ZT_NETWORK_AUTOCONF_DELAY / 3) @@ -128,27 +129,25 @@ Membership::AddCredentialResult Membership::addCredential(const RuntimeEnvironme { const uint64_t newts = com.timestamp(); if (newts <= _comRevocationThreshold) { - TRACE("addCredential(CertificateOfMembership) for %s on %.16llx REJECTED (revoked)",com.issuedTo().toString().c_str(),com.networkId()); + RR->t->credentialRejected(com,"revoked"); return ADD_REJECTED; } const uint64_t oldts = _com.timestamp(); if (newts < oldts) { - TRACE("addCredential(CertificateOfMembership) for %s on %.16llx REJECTED (older than current)",com.issuedTo().toString().c_str(),com.networkId()); + RR->t->credentialRejected(com,"old"); return ADD_REJECTED; } - if ((newts == oldts)&&(_com == com)) { - TRACE("addCredential(CertificateOfMembership) for %s on %.16llx ACCEPTED (redundant)",com.issuedTo().toString().c_str(),com.networkId()); + if ((newts == oldts)&&(_com == com)) return ADD_ACCEPTED_REDUNDANT; - } switch(com.verify(RR,tPtr)) { default: - TRACE("addCredential(CertificateOfMembership) for %s on %.16llx REJECTED (invalid signature or object)",com.issuedTo().toString().c_str(),com.networkId()); + RR->t->credentialRejected(com,"invalid"); return ADD_REJECTED; case 0: - TRACE("addCredential(CertificateOfMembership) for %s on %.16llx ACCEPTED (new)",com.issuedTo().toString().c_str(),com.networkId()); _com = com; + RR->t->credentialAccepted(com); return ADD_ACCEPTED_NEW; case 1: return ADD_DEFERRED_FOR_WHOIS; @@ -162,27 +161,25 @@ static Membership::AddCredentialResult _addCredImpl(Hashtable<uint32_t,C> &remot C *rc = remoteCreds.get(cred.id()); if (rc) { if (rc->timestamp() > cred.timestamp()) { - TRACE("addCredential(type==%d) for %s on %.16llx REJECTED (older than credential we have)",(int)C::credentialType(),cred.issuedTo().toString().c_str(),cred.networkId()); + RR->t->credentialRejected(cred,"old"); return Membership::ADD_REJECTED; } - if (*rc == cred) { - //TRACE("addCredential(type==%d) for %s on %.16llx ACCEPTED (redundant)",(int)C::credentialType(),cred.issuedTo().toString().c_str(),cred.networkId()); + if (*rc == cred) return Membership::ADD_ACCEPTED_REDUNDANT; - } } const uint64_t *const rt = revocations.get(Membership::credentialKey(C::credentialType(),cred.id())); if ((rt)&&(*rt >= cred.timestamp())) { - TRACE("addCredential(type==%d) for %s on %.16llx REJECTED (timestamp below revocation threshold)",(int)C::credentialType(),cred.issuedTo().toString().c_str(),cred.networkId()); + RR->t->credentialRejected(cred,"revoked"); return Membership::ADD_REJECTED; } switch(cred.verify(RR,tPtr)) { default: - TRACE("addCredential(type==%d) for %s on %.16llx REJECTED (invalid)",(int)C::credentialType(),cred.issuedTo().toString().c_str(),cred.networkId()); + RR->t->credentialRejected(cred,"invalid"); return Membership::ADD_REJECTED; case 0: - TRACE("addCredential(type==%d) for %s on %.16llx ACCEPTED (new)",(int)C::credentialType(),cred.issuedTo().toString().c_str(),cred.networkId()); + RR->t->credentialAccepted(cred); if (!rc) rc = &(remoteCreds[cred.id()]); *rc = cred; @@ -201,12 +198,14 @@ Membership::AddCredentialResult Membership::addCredential(const RuntimeEnvironme uint64_t *rt; switch(rev.verify(RR,tPtr)) { default: + RR->t->credentialRejected(rev,"invalid"); return ADD_REJECTED; case 0: { const Credential::Type ct = rev.type(); switch(ct) { case Credential::CREDENTIAL_TYPE_COM: if (rev.threshold() > _comRevocationThreshold) { + RR->t->credentialAccepted(rev); _comRevocationThreshold = rev.threshold(); return ADD_ACCEPTED_NEW; } @@ -217,10 +216,12 @@ Membership::AddCredentialResult Membership::addCredential(const RuntimeEnvironme rt = &(_revocations[credentialKey(ct,rev.credentialId())]); if (*rt < rev.threshold()) { *rt = rev.threshold(); + _comRevocationThreshold = rev.threshold(); return ADD_ACCEPTED_NEW; } return ADD_ACCEPTED_REDUNDANT; default: + RR->t->credentialRejected(rev,"invalid"); return ADD_REJECTED; } } diff --git a/node/Multicaster.cpp b/node/Multicaster.cpp index 52213364..fb7b068f 100644 --- a/node/Multicaster.cpp +++ b/node/Multicaster.cpp @@ -139,8 +139,6 @@ restart_member_scan: appendTo.setAt(totalAt,(uint32_t)totalKnown); appendTo.setAt(addedAt,(uint16_t)added); - //TRACE("..MC Multicaster::gather() attached %u of %u peers for %.16llx/%s (2)",n,(unsigned int)(gs->second.members.size() - skipped),nwid,mg.toString().c_str()); - return added; } @@ -386,8 +384,6 @@ void Multicaster::_add(void *tPtr,uint64_t now,uint64_t nwid,const MulticastGrou gs.members.push_back(MulticastGroupMember(member,now)); - //TRACE("..MC %s joined multicast group %.16llx/%s via %s",member.toString().c_str(),nwid,mg.toString().c_str(),((learnedFrom) ? learnedFrom.toString().c_str() : "(direct)")); - for(std::list<OutboundMulticast>::iterator tx(gs.txQueue.begin());tx!=gs.txQueue.end();) { if (tx->atLimit()) gs.txQueue.erase(tx++); diff --git a/node/Network.cpp b/node/Network.cpp index f2b6771b..575b0170 100644 --- a/node/Network.cpp +++ b/node/Network.cpp @@ -42,89 +42,12 @@ #include "NetworkController.hpp" #include "Node.hpp" #include "Peer.hpp" - -// Uncomment to make the rules engine dump trace info to stdout -//#define ZT_RULES_ENGINE_DEBUGGING 1 +#include "Trace.hpp" namespace ZeroTier { namespace { -#ifdef ZT_RULES_ENGINE_DEBUGGING -#define FILTER_TRACE(f,...) { snprintf(dpbuf,sizeof(dpbuf),f,##__VA_ARGS__); dlog.push_back(std::string(dpbuf)); } -static const char *_rtn(const ZT_VirtualNetworkRuleType rt) -{ - switch(rt) { - case ZT_NETWORK_RULE_ACTION_DROP: return "ACTION_DROP"; - case ZT_NETWORK_RULE_ACTION_ACCEPT: return "ACTION_ACCEPT"; - case ZT_NETWORK_RULE_ACTION_TEE: return "ACTION_TEE"; - case ZT_NETWORK_RULE_ACTION_WATCH: return "ACTION_WATCH"; - case ZT_NETWORK_RULE_ACTION_REDIRECT: return "ACTION_REDIRECT"; - case ZT_NETWORK_RULE_ACTION_BREAK: return "ACTION_BREAK"; - case ZT_NETWORK_RULE_MATCH_SOURCE_ZEROTIER_ADDRESS: return "MATCH_SOURCE_ZEROTIER_ADDRESS"; - case ZT_NETWORK_RULE_MATCH_DEST_ZEROTIER_ADDRESS: return "MATCH_DEST_ZEROTIER_ADDRESS"; - case ZT_NETWORK_RULE_MATCH_VLAN_ID: return "MATCH_VLAN_ID"; - case ZT_NETWORK_RULE_MATCH_VLAN_PCP: return "MATCH_VLAN_PCP"; - case ZT_NETWORK_RULE_MATCH_VLAN_DEI: return "MATCH_VLAN_DEI"; - case ZT_NETWORK_RULE_MATCH_MAC_SOURCE: return "MATCH_MAC_SOURCE"; - case ZT_NETWORK_RULE_MATCH_MAC_DEST: return "MATCH_MAC_DEST"; - case ZT_NETWORK_RULE_MATCH_IPV4_SOURCE: return "MATCH_IPV4_SOURCE"; - case ZT_NETWORK_RULE_MATCH_IPV4_DEST: return "MATCH_IPV4_DEST"; - case ZT_NETWORK_RULE_MATCH_IPV6_SOURCE: return "MATCH_IPV6_SOURCE"; - case ZT_NETWORK_RULE_MATCH_IPV6_DEST: return "MATCH_IPV6_DEST"; - case ZT_NETWORK_RULE_MATCH_IP_TOS: return "MATCH_IP_TOS"; - case ZT_NETWORK_RULE_MATCH_IP_PROTOCOL: return "MATCH_IP_PROTOCOL"; - case ZT_NETWORK_RULE_MATCH_ETHERTYPE: return "MATCH_ETHERTYPE"; - case ZT_NETWORK_RULE_MATCH_ICMP: return "MATCH_ICMP"; - case ZT_NETWORK_RULE_MATCH_IP_SOURCE_PORT_RANGE: return "MATCH_IP_SOURCE_PORT_RANGE"; - case ZT_NETWORK_RULE_MATCH_IP_DEST_PORT_RANGE: return "MATCH_IP_DEST_PORT_RANGE"; - case ZT_NETWORK_RULE_MATCH_CHARACTERISTICS: return "MATCH_CHARACTERISTICS"; - case ZT_NETWORK_RULE_MATCH_FRAME_SIZE_RANGE: return "MATCH_FRAME_SIZE_RANGE"; - case ZT_NETWORK_RULE_MATCH_TAGS_DIFFERENCE: return "MATCH_TAGS_DIFFERENCE"; - case ZT_NETWORK_RULE_MATCH_TAGS_BITWISE_AND: return "MATCH_TAGS_BITWISE_AND"; - case ZT_NETWORK_RULE_MATCH_TAGS_BITWISE_OR: return "MATCH_TAGS_BITWISE_OR"; - case ZT_NETWORK_RULE_MATCH_TAGS_BITWISE_XOR: return "MATCH_TAGS_BITWISE_XOR"; - default: return "???"; - } -} -static const void _dumpFilterTrace(const char *ruleName,uint8_t thisSetMatches,bool inbound,const Address &ztSource,const Address &ztDest,const MAC &macSource,const MAC &macDest,const std::vector<std::string> &dlog,unsigned int frameLen,unsigned int etherType,const char *msg) -{ - static volatile unsigned long cnt = 0; - printf("%.6lu %c %s %s frameLen=%u etherType=%u" ZT_EOL_S, - cnt++, - ((thisSetMatches) ? 'Y' : '.'), - ruleName, - ((inbound) ? "INBOUND" : "OUTBOUND"), - frameLen, - etherType - ); - for(std::vector<std::string>::const_iterator m(dlog.begin());m!=dlog.end();++m) - printf(" | %s" ZT_EOL_S,m->c_str()); - printf(" + %c %s->%s %.2x:%.2x:%.2x:%.2x:%.2x:%.2x->%.2x:%.2x:%.2x:%.2x:%.2x:%.2x" ZT_EOL_S, - ((thisSetMatches) ? 'Y' : '.'), - ztSource.toString().c_str(), - ztDest.toString().c_str(), - (unsigned int)macSource[0], - (unsigned int)macSource[1], - (unsigned int)macSource[2], - (unsigned int)macSource[3], - (unsigned int)macSource[4], - (unsigned int)macSource[5], - (unsigned int)macDest[0], - (unsigned int)macDest[1], - (unsigned int)macDest[2], - (unsigned int)macDest[3], - (unsigned int)macDest[4], - (unsigned int)macDest[5] - ); - if (msg) - printf(" + (%s)" ZT_EOL_S,msg); - fflush(stdout); -} -#else -#define FILTER_TRACE(f,...) {} -#endif // ZT_RULES_ENGINE_DEBUGGING - // Returns true if packet appears valid; pos and proto will be set static bool _ipv6GetPayload(const uint8_t *frameData,unsigned int frameLen,unsigned int &pos,unsigned int &proto) { @@ -162,8 +85,10 @@ enum _doZtFilterResult DOZTFILTER_ACCEPT, DOZTFILTER_SUPER_ACCEPT }; + static _doZtFilterResult _doZtFilter( const RuntimeEnvironment *RR, + Trace::RuleResultLog &rrl, const NetworkConfig &nconf, const Membership *membership, // can be NULL const bool inbound, @@ -181,11 +106,6 @@ static _doZtFilterResult _doZtFilter( unsigned int &ccLength, // MUTABLE -- set to length of packet payload to TEE bool &ccWatch) // MUTABLE -- set to true for WATCH target as opposed to normal TEE { -#ifdef ZT_RULES_ENGINE_DEBUGGING - char dpbuf[1024]; // used by FILTER_TRACE macro - std::vector<std::string> dlog; -#endif // ZT_RULES_ENGINE_DEBUGGING - // Set to true if we are a TEE/REDIRECT/WATCH target bool superAccept = false; @@ -193,6 +113,8 @@ static _doZtFilterResult _doZtFilter( // ACTION with no MATCH entries preceding it is always taken. uint8_t thisSetMatches = 1; + rrl.clear(); + for(unsigned int rn=0;rn<ruleCount;++rn) { const ZT_VirtualNetworkRuleType rt = (ZT_VirtualNetworkRuleType)(rules[rn].t & 0x3f); @@ -201,15 +123,9 @@ static _doZtFilterResult _doZtFilter( if (thisSetMatches) { switch(rt) { case ZT_NETWORK_RULE_ACTION_DROP: -#ifdef ZT_RULES_ENGINE_DEBUGGING - _dumpFilterTrace("ACTION_DROP",thisSetMatches,inbound,ztSource,ztDest,macSource,macDest,dlog,frameLen,etherType,(const char *)0); -#endif // ZT_RULES_ENGINE_DEBUGGING return DOZTFILTER_DROP; case ZT_NETWORK_RULE_ACTION_ACCEPT: -#ifdef ZT_RULES_ENGINE_DEBUGGING - _dumpFilterTrace("ACTION_ACCEPT",thisSetMatches,inbound,ztSource,ztDest,macSource,macDest,dlog,frameLen,etherType,(const char *)0); -#endif // ZT_RULES_ENGINE_DEBUGGING return (superAccept ? DOZTFILTER_SUPER_ACCEPT : DOZTFILTER_ACCEPT); // match, accept packet // These are initially handled together since preliminary logic is common @@ -218,39 +134,18 @@ static _doZtFilterResult _doZtFilter( case ZT_NETWORK_RULE_ACTION_REDIRECT: { const Address fwdAddr(rules[rn].v.fwd.address); if (fwdAddr == ztSource) { -#ifdef ZT_RULES_ENGINE_DEBUGGING - _dumpFilterTrace(_rtn(rt),thisSetMatches,inbound,ztSource,ztDest,macSource,macDest,dlog,frameLen,etherType,"skipped as no-op since source is target"); - dlog.clear(); -#endif // ZT_RULES_ENGINE_DEBUGGING + // Skip as no-op since source is target } else if (fwdAddr == RR->identity.address()) { if (inbound) { -#ifdef ZT_RULES_ENGINE_DEBUGGING - _dumpFilterTrace(_rtn(rt),thisSetMatches,inbound,ztSource,ztDest,macSource,macDest,dlog,frameLen,etherType,"interpreted as super-ACCEPT on inbound since we are target"); -#endif // ZT_RULES_ENGINE_DEBUGGING return DOZTFILTER_SUPER_ACCEPT; } else { -#ifdef ZT_RULES_ENGINE_DEBUGGING - _dumpFilterTrace(_rtn(rt),thisSetMatches,inbound,ztSource,ztDest,macSource,macDest,dlog,frameLen,etherType,"skipped as no-op on outbound since we are target"); - dlog.clear(); -#endif // ZT_RULES_ENGINE_DEBUGGING } } else if (fwdAddr == ztDest) { -#ifdef ZT_RULES_ENGINE_DEBUGGING - _dumpFilterTrace(_rtn(rt),thisSetMatches,inbound,ztSource,ztDest,macSource,macDest,dlog,frameLen,etherType,"skipped as no-op because destination is already target"); - dlog.clear(); -#endif // ZT_RULES_ENGINE_DEBUGGING } else { if (rt == ZT_NETWORK_RULE_ACTION_REDIRECT) { -#ifdef ZT_RULES_ENGINE_DEBUGGING - _dumpFilterTrace("ACTION_REDIRECT",thisSetMatches,inbound,ztSource,ztDest,macSource,macDest,dlog,frameLen,etherType,(const char *)0); -#endif // ZT_RULES_ENGINE_DEBUGGING ztDest = fwdAddr; return DOZTFILTER_REDIRECT; } else { -#ifdef ZT_RULES_ENGINE_DEBUGGING - _dumpFilterTrace(_rtn(rt),thisSetMatches,inbound,ztSource,ztDest,macSource,macDest,dlog,frameLen,etherType,(const char *)0); - dlog.clear(); -#endif // ZT_RULES_ENGINE_DEBUGGING cc = fwdAddr; ccLength = (rules[rn].v.fwd.length != 0) ? ((frameLen < (unsigned int)rules[rn].v.fwd.length) ? frameLen : (unsigned int)rules[rn].v.fwd.length) : frameLen; ccWatch = (rt == ZT_NETWORK_RULE_ACTION_WATCH); @@ -259,18 +154,10 @@ static _doZtFilterResult _doZtFilter( } continue; case ZT_NETWORK_RULE_ACTION_BREAK: -#ifdef ZT_RULES_ENGINE_DEBUGGING - _dumpFilterTrace("ACTION_BREAK",thisSetMatches,inbound,ztSource,ztDest,macSource,macDest,dlog,frameLen,etherType,(const char *)0); - dlog.clear(); -#endif // ZT_RULES_ENGINE_DEBUGGING return DOZTFILTER_NO_MATCH; // Unrecognized ACTIONs are ignored as no-ops default: -#ifdef ZT_RULES_ENGINE_DEBUGGING - _dumpFilterTrace(_rtn(rt),thisSetMatches,inbound,ztSource,ztDest,macSource,macDest,dlog,frameLen,etherType,(const char *)0); - dlog.clear(); -#endif // ZT_RULES_ENGINE_DEBUGGING continue; } } else { @@ -290,10 +177,6 @@ static _doZtFilterResult _doZtFilter( } } -#ifdef ZT_RULES_ENGINE_DEBUGGING - _dumpFilterTrace(_rtn(rt),thisSetMatches,inbound,ztSource,ztDest,macSource,macDest,dlog,frameLen,etherType,(const char *)0); - dlog.clear(); -#endif // ZT_RULES_ENGINE_DEBUGGING thisSetMatches = 1; // reset to default true for next batch of entries continue; } @@ -301,8 +184,10 @@ static _doZtFilterResult _doZtFilter( // Circuit breaker: no need to evaluate an AND if the set's match state // is currently false since anything AND false is false. - if ((!thisSetMatches)&&(!(rules[rn].t & 0x40))) + if ((!thisSetMatches)&&(!(rules[rn].t & 0x40))) { + rrl.logSkipped(rn,thisSetMatches); continue; + } // If this was not an ACTION evaluate next MATCH and update thisSetMatches with (AND [result]) uint8_t thisRuleMatches = 0; @@ -310,106 +195,82 @@ static _doZtFilterResult _doZtFilter( switch(rt) { case ZT_NETWORK_RULE_MATCH_SOURCE_ZEROTIER_ADDRESS: thisRuleMatches = (uint8_t)(rules[rn].v.zt == ztSource.toInt()); - FILTER_TRACE("%u %s %c %.10llx==%.10llx -> %u",rn,_rtn(rt),(((rules[rn].t & 0x80) != 0) ? '!' : '='),rules[rn].v.zt,ztSource.toInt(),(unsigned int)thisRuleMatches); break; case ZT_NETWORK_RULE_MATCH_DEST_ZEROTIER_ADDRESS: thisRuleMatches = (uint8_t)(rules[rn].v.zt == ztDest.toInt()); - FILTER_TRACE("%u %s %c %.10llx==%.10llx -> %u",rn,_rtn(rt),(((rules[rn].t & 0x80) != 0) ? '!' : '='),rules[rn].v.zt,ztDest.toInt(),(unsigned int)thisRuleMatches); break; case ZT_NETWORK_RULE_MATCH_VLAN_ID: thisRuleMatches = (uint8_t)(rules[rn].v.vlanId == (uint16_t)vlanId); - FILTER_TRACE("%u %s %c %u==%u -> %u",rn,_rtn(rt),(((rules[rn].t & 0x80) != 0) ? '!' : '='),(unsigned int)rules[rn].v.vlanId,(unsigned int)vlanId,(unsigned int)thisRuleMatches); break; case ZT_NETWORK_RULE_MATCH_VLAN_PCP: // NOT SUPPORTED YET thisRuleMatches = (uint8_t)(rules[rn].v.vlanPcp == 0); - FILTER_TRACE("%u %s %c %u==%u -> %u",rn,_rtn(rt),(((rules[rn].t & 0x80) != 0) ? '!' : '='),(unsigned int)rules[rn].v.vlanPcp,0,(unsigned int)thisRuleMatches); break; case ZT_NETWORK_RULE_MATCH_VLAN_DEI: // NOT SUPPORTED YET thisRuleMatches = (uint8_t)(rules[rn].v.vlanDei == 0); - FILTER_TRACE("%u %s %c %u==%u -> %u",rn,_rtn(rt),(((rules[rn].t & 0x80) != 0) ? '!' : '='),(unsigned int)rules[rn].v.vlanDei,0,(unsigned int)thisRuleMatches); break; case ZT_NETWORK_RULE_MATCH_MAC_SOURCE: thisRuleMatches = (uint8_t)(MAC(rules[rn].v.mac,6) == macSource); - FILTER_TRACE("%u %s %c %.12llx=%.12llx -> %u",rn,_rtn(rt),(((rules[rn].t & 0x80) != 0) ? '!' : '='),rules[rn].v.mac,macSource.toInt(),(unsigned int)thisRuleMatches); break; case ZT_NETWORK_RULE_MATCH_MAC_DEST: thisRuleMatches = (uint8_t)(MAC(rules[rn].v.mac,6) == macDest); - FILTER_TRACE("%u %s %c %.12llx=%.12llx -> %u",rn,_rtn(rt),(((rules[rn].t & 0x80) != 0) ? '!' : '='),rules[rn].v.mac,macDest.toInt(),(unsigned int)thisRuleMatches); break; case ZT_NETWORK_RULE_MATCH_IPV4_SOURCE: if ((etherType == ZT_ETHERTYPE_IPV4)&&(frameLen >= 20)) { thisRuleMatches = (uint8_t)(InetAddress((const void *)&(rules[rn].v.ipv4.ip),4,rules[rn].v.ipv4.mask).containsAddress(InetAddress((const void *)(frameData + 12),4,0))); - FILTER_TRACE("%u %s %c %s contains %s -> %u",rn,_rtn(rt),(((rules[rn].t & 0x80) != 0) ? '!' : '='),InetAddress((const void *)&(rules[rn].v.ipv4.ip),4,rules[rn].v.ipv4.mask).toString().c_str(),InetAddress((const void *)(frameData + 12),4,0).toIpString().c_str(),(unsigned int)thisRuleMatches); } else { thisRuleMatches = 0; - FILTER_TRACE("%u %s %c [frame not IPv4] -> 0",rn,_rtn(rt),(((rules[rn].t & 0x80) != 0) ? '!' : '=')); } break; case ZT_NETWORK_RULE_MATCH_IPV4_DEST: if ((etherType == ZT_ETHERTYPE_IPV4)&&(frameLen >= 20)) { thisRuleMatches = (uint8_t)(InetAddress((const void *)&(rules[rn].v.ipv4.ip),4,rules[rn].v.ipv4.mask).containsAddress(InetAddress((const void *)(frameData + 16),4,0))); - FILTER_TRACE("%u %s %c %s contains %s -> %u",rn,_rtn(rt),(((rules[rn].t & 0x80) != 0) ? '!' : '='),InetAddress((const void *)&(rules[rn].v.ipv4.ip),4,rules[rn].v.ipv4.mask).toString().c_str(),InetAddress((const void *)(frameData + 16),4,0).toIpString().c_str(),(unsigned int)thisRuleMatches); } else { thisRuleMatches = 0; - FILTER_TRACE("%u %s %c [frame not IPv4] -> 0",rn,_rtn(rt),(((rules[rn].t & 0x80) != 0) ? '!' : '=')); } break; case ZT_NETWORK_RULE_MATCH_IPV6_SOURCE: if ((etherType == ZT_ETHERTYPE_IPV6)&&(frameLen >= 40)) { thisRuleMatches = (uint8_t)(InetAddress((const void *)rules[rn].v.ipv6.ip,16,rules[rn].v.ipv6.mask).containsAddress(InetAddress((const void *)(frameData + 8),16,0))); - FILTER_TRACE("%u %s %c %s contains %s -> %u",rn,_rtn(rt),(((rules[rn].t & 0x80) != 0) ? '!' : '='),InetAddress((const void *)rules[rn].v.ipv6.ip,16,rules[rn].v.ipv6.mask).toString().c_str(),InetAddress((const void *)(frameData + 8),16,0).toIpString().c_str(),(unsigned int)thisRuleMatches); } else { thisRuleMatches = 0; - FILTER_TRACE("%u %s %c [frame not IPv6] -> 0",rn,_rtn(rt),(((rules[rn].t & 0x80) != 0) ? '!' : '=')); } break; case ZT_NETWORK_RULE_MATCH_IPV6_DEST: if ((etherType == ZT_ETHERTYPE_IPV6)&&(frameLen >= 40)) { thisRuleMatches = (uint8_t)(InetAddress((const void *)rules[rn].v.ipv6.ip,16,rules[rn].v.ipv6.mask).containsAddress(InetAddress((const void *)(frameData + 24),16,0))); - FILTER_TRACE("%u %s %c %s contains %s -> %u",rn,_rtn(rt),(((rules[rn].t & 0x80) != 0) ? '!' : '='),InetAddress((const void *)rules[rn].v.ipv6.ip,16,rules[rn].v.ipv6.mask).toString().c_str(),InetAddress((const void *)(frameData + 24),16,0).toIpString().c_str(),(unsigned int)thisRuleMatches); } else { thisRuleMatches = 0; - FILTER_TRACE("%u %s %c [frame not IPv6] -> 0",rn,_rtn(rt),(((rules[rn].t & 0x80) != 0) ? '!' : '=')); } break; case ZT_NETWORK_RULE_MATCH_IP_TOS: if ((etherType == ZT_ETHERTYPE_IPV4)&&(frameLen >= 20)) { - //thisRuleMatches = (uint8_t)(rules[rn].v.ipTos == ((frameData[1] & 0xfc) >> 2)); const uint8_t tosMasked = frameData[1] & rules[rn].v.ipTos.mask; thisRuleMatches = (uint8_t)((tosMasked >= rules[rn].v.ipTos.value[0])&&(tosMasked <= rules[rn].v.ipTos.value[1])); - FILTER_TRACE("%u %s %c (IPv4) %u&%u==%u-%u -> %u",rn,_rtn(rt),(((rules[rn].t & 0x80) != 0) ? '!' : '='),(unsigned int)tosMasked,(unsigned int)rules[rn].v.ipTos.mask,(unsigned int)rules[rn].v.ipTos.value[0],(unsigned int)rules[rn].v.ipTos.value[1],(unsigned int)thisRuleMatches); } else if ((etherType == ZT_ETHERTYPE_IPV6)&&(frameLen >= 40)) { const uint8_t tosMasked = (((frameData[0] << 4) & 0xf0) | ((frameData[1] >> 4) & 0x0f)) & rules[rn].v.ipTos.mask; thisRuleMatches = (uint8_t)((tosMasked >= rules[rn].v.ipTos.value[0])&&(tosMasked <= rules[rn].v.ipTos.value[1])); - FILTER_TRACE("%u %s %c (IPv4) %u&%u==%u-%u -> %u",rn,_rtn(rt),(((rules[rn].t & 0x80) != 0) ? '!' : '='),(unsigned int)tosMasked,(unsigned int)rules[rn].v.ipTos.mask,(unsigned int)rules[rn].v.ipTos.value[0],(unsigned int)rules[rn].v.ipTos.value[1],(unsigned int)thisRuleMatches); } else { thisRuleMatches = 0; - FILTER_TRACE("%u %s %c [frame not IP] -> 0",rn,_rtn(rt),(((rules[rn].t & 0x80) != 0) ? '!' : '=')); } break; case ZT_NETWORK_RULE_MATCH_IP_PROTOCOL: if ((etherType == ZT_ETHERTYPE_IPV4)&&(frameLen >= 20)) { thisRuleMatches = (uint8_t)(rules[rn].v.ipProtocol == frameData[9]); - FILTER_TRACE("%u %s %c (IPv4) %u==%u -> %u",rn,_rtn(rt),(((rules[rn].t & 0x80) != 0) ? '!' : '='),(unsigned int)rules[rn].v.ipProtocol,(unsigned int)frameData[9],(unsigned int)thisRuleMatches); } else if (etherType == ZT_ETHERTYPE_IPV6) { unsigned int pos = 0,proto = 0; if (_ipv6GetPayload(frameData,frameLen,pos,proto)) { thisRuleMatches = (uint8_t)(rules[rn].v.ipProtocol == (uint8_t)proto); - FILTER_TRACE("%u %s %c (IPv6) %u==%u -> %u",rn,_rtn(rt),(((rules[rn].t & 0x80) != 0) ? '!' : '='),(unsigned int)rules[rn].v.ipProtocol,proto,(unsigned int)thisRuleMatches); } else { thisRuleMatches = 0; - FILTER_TRACE("%u %s %c [invalid IPv6] -> 0",rn,_rtn(rt),(((rules[rn].t & 0x80) != 0) ? '!' : '=')); } } else { thisRuleMatches = 0; - FILTER_TRACE("%u %s %c [frame not IP] -> 0",rn,_rtn(rt),(((rules[rn].t & 0x80) != 0) ? '!' : '=')); } break; case ZT_NETWORK_RULE_MATCH_ETHERTYPE: thisRuleMatches = (uint8_t)(rules[rn].v.etherType == (uint16_t)etherType); - FILTER_TRACE("%u %s %c %u==%u -> %u",rn,_rtn(rt),(((rules[rn].t & 0x80) != 0) ? '!' : '='),(unsigned int)rules[rn].v.etherType,etherType,(unsigned int)thisRuleMatches); break; case ZT_NETWORK_RULE_MATCH_ICMP: if ((etherType == ZT_ETHERTYPE_IPV4)&&(frameLen >= 20)) { @@ -425,14 +286,11 @@ static _doZtFilterResult _doZtFilter( } else { thisRuleMatches = 0; } - FILTER_TRACE("%u %s %c (IPv4) icmp-type:%d==%d icmp-code:%d==%d -> %u",rn,_rtn(rt),(((rules[rn].t & 0x80) != 0) ? '!' : '='),(int)frameData[ihl],(int)rules[rn].v.icmp.type,(int)frameData[ihl+1],(((rules[rn].v.icmp.flags & 0x01) != 0) ? (int)rules[rn].v.icmp.code : -1),(unsigned int)thisRuleMatches); } else { thisRuleMatches = 0; - FILTER_TRACE("%u %s %c [IPv4 frame invalid] -> 0",rn,_rtn(rt),(((rules[rn].t & 0x80) != 0) ? '!' : '=')); } } else { thisRuleMatches = 0; - FILTER_TRACE("%u %s %c [frame not ICMP] -> 0",rn,_rtn(rt),(((rules[rn].t & 0x80) != 0) ? '!' : '=')); } } else if (etherType == ZT_ETHERTYPE_IPV6) { unsigned int pos = 0,proto = 0; @@ -447,21 +305,16 @@ static _doZtFilterResult _doZtFilter( } else { thisRuleMatches = 0; } - FILTER_TRACE("%u %s %c (IPv6) icmp-type:%d==%d icmp-code:%d==%d -> %u",rn,_rtn(rt),(((rules[rn].t & 0x80) != 0) ? '!' : '='),(int)frameData[pos],(int)rules[rn].v.icmp.type,(int)frameData[pos+1],(((rules[rn].v.icmp.flags & 0x01) != 0) ? (int)rules[rn].v.icmp.code : -1),(unsigned int)thisRuleMatches); } else { thisRuleMatches = 0; - FILTER_TRACE("%u %s %c [frame not ICMPv6] -> 0",rn,_rtn(rt),(((rules[rn].t & 0x80) != 0) ? '!' : '=')); } } else { thisRuleMatches = 0; - FILTER_TRACE("%u %s %c [invalid IPv6] -> 0",rn,_rtn(rt),(((rules[rn].t & 0x80) != 0) ? '!' : '=')); } } else { thisRuleMatches = 0; - FILTER_TRACE("%u %s %c [frame not IP] -> 0",rn,_rtn(rt),(((rules[rn].t & 0x80) != 0) ? '!' : '=')); } break; - break; case ZT_NETWORK_RULE_MATCH_IP_SOURCE_PORT_RANGE: case ZT_NETWORK_RULE_MATCH_IP_DEST_PORT_RANGE: if ((etherType == ZT_ETHERTYPE_IPV4)&&(frameLen >= 20)) { @@ -482,7 +335,6 @@ static _doZtFilterResult _doZtFilter( } thisRuleMatches = (p >= 0) ? (uint8_t)((p >= (int)rules[rn].v.port[0])&&(p <= (int)rules[rn].v.port[1])) : (uint8_t)0; - FILTER_TRACE("%u %s %c (IPv4) %d in %d-%d -> %u",rn,_rtn(rt),(((rules[rn].t & 0x80) != 0) ? '!' : '='),p,(int)rules[rn].v.port[0],(int)rules[rn].v.port[1],(unsigned int)thisRuleMatches); } else if (etherType == ZT_ETHERTYPE_IPV6) { unsigned int pos = 0,proto = 0; if (_ipv6GetPayload(frameData,frameLen,pos,proto)) { @@ -501,14 +353,11 @@ static _doZtFilterResult _doZtFilter( break; } thisRuleMatches = (p > 0) ? (uint8_t)((p >= (int)rules[rn].v.port[0])&&(p <= (int)rules[rn].v.port[1])) : (uint8_t)0; - FILTER_TRACE("%u %s %c (IPv6) %d in %d-%d -> %u",rn,_rtn(rt),(((rules[rn].t & 0x80) != 0) ? '!' : '='),p,(int)rules[rn].v.port[0],(int)rules[rn].v.port[1],(unsigned int)thisRuleMatches); } else { thisRuleMatches = 0; - FILTER_TRACE("%u %s %c [invalid IPv6] -> 0",rn,_rtn(rt),(((rules[rn].t & 0x80) != 0) ? '!' : '=')); } } else { thisRuleMatches = 0; - FILTER_TRACE("%u %s %c [frame not IP] -> 0",rn,_rtn(rt),(((rules[rn].t & 0x80) != 0) ? '!' : '=')); } break; case ZT_NETWORK_RULE_MATCH_CHARACTERISTICS: { @@ -570,15 +419,12 @@ static _doZtFilterResult _doZtFilter( } } thisRuleMatches = (uint8_t)((cf & rules[rn].v.characteristics) != 0); - FILTER_TRACE("%u %s %c (%.16llx | %.16llx)!=0 -> %u",rn,_rtn(rt),(((rules[rn].t & 0x80) != 0) ? '!' : '='),cf,rules[rn].v.characteristics,(unsigned int)thisRuleMatches); } break; case ZT_NETWORK_RULE_MATCH_FRAME_SIZE_RANGE: thisRuleMatches = (uint8_t)((frameLen >= (unsigned int)rules[rn].v.frameSize[0])&&(frameLen <= (unsigned int)rules[rn].v.frameSize[1])); - FILTER_TRACE("%u %s %c %u in %u-%u -> %u",rn,_rtn(rt),(((rules[rn].t & 0x80) != 0) ? '!' : '='),frameLen,(unsigned int)rules[rn].v.frameSize[0],(unsigned int)rules[rn].v.frameSize[1],(unsigned int)thisRuleMatches); break; case ZT_NETWORK_RULE_MATCH_RANDOM: thisRuleMatches = (uint8_t)((uint32_t)(RR->node->prng() & 0xffffffffULL) <= rules[rn].v.randomProbability); - FILTER_TRACE("%u %s %c -> %u",rn,_rtn(rt),(((rules[rn].t & 0x80) != 0) ? '!' : '='),(unsigned int)thisRuleMatches); break; case ZT_NETWORK_RULE_MATCH_TAGS_DIFFERENCE: case ZT_NETWORK_RULE_MATCH_TAGS_BITWISE_AND: @@ -594,26 +440,20 @@ static _doZtFilterResult _doZtFilter( if (rt == ZT_NETWORK_RULE_MATCH_TAGS_DIFFERENCE) { const uint32_t diff = (ltv > rtv) ? (ltv - rtv) : (rtv - ltv); thisRuleMatches = (uint8_t)(diff <= rules[rn].v.tag.value); - FILTER_TRACE("%u %s %c TAG %u local:%u remote:%u difference:%u<=%u -> %u",rn,_rtn(rt),(((rules[rn].t & 0x80) != 0) ? '!' : '='),(unsigned int)rules[rn].v.tag.id,ltv,rtv,diff,(unsigned int)rules[rn].v.tag.value,thisRuleMatches); } else if (rt == ZT_NETWORK_RULE_MATCH_TAGS_BITWISE_AND) { thisRuleMatches = (uint8_t)((ltv & rtv) == rules[rn].v.tag.value); - FILTER_TRACE("%u %s %c TAG %u local:%.8x & remote:%.8x == %.8x -> %u",rn,_rtn(rt),(((rules[rn].t & 0x80) != 0) ? '!' : '='),(unsigned int)rules[rn].v.tag.id,ltv,rtv,(unsigned int)rules[rn].v.tag.value,(unsigned int)thisRuleMatches); } else if (rt == ZT_NETWORK_RULE_MATCH_TAGS_BITWISE_OR) { thisRuleMatches = (uint8_t)((ltv | rtv) == rules[rn].v.tag.value); - FILTER_TRACE("%u %s %c TAG %u local:%.8x | remote:%.8x == %.8x -> %u",rn,_rtn(rt),(((rules[rn].t & 0x80) != 0) ? '!' : '='),(unsigned int)rules[rn].v.tag.id,ltv,rtv,(unsigned int)rules[rn].v.tag.value,(unsigned int)thisRuleMatches); } else if (rt == ZT_NETWORK_RULE_MATCH_TAGS_BITWISE_XOR) { thisRuleMatches = (uint8_t)((ltv ^ rtv) == rules[rn].v.tag.value); - FILTER_TRACE("%u %s %c TAG %u local:%.8x ^ remote:%.8x == %.8x -> %u",rn,_rtn(rt),(((rules[rn].t & 0x80) != 0) ? '!' : '='),(unsigned int)rules[rn].v.tag.id,ltv,rtv,(unsigned int)rules[rn].v.tag.value,(unsigned int)thisRuleMatches); } else if (rt == ZT_NETWORK_RULE_MATCH_TAGS_EQUAL) { thisRuleMatches = (uint8_t)((ltv == rules[rn].v.tag.value)&&(rtv == rules[rn].v.tag.value)); - FILTER_TRACE("%u %s %c TAG %u local:%.8x and remote:%.8x == %.8x -> %u",rn,_rtn(rt),(((rules[rn].t & 0x80) != 0) ? '!' : '='),(unsigned int)rules[rn].v.tag.id,ltv,rtv,(unsigned int)rules[rn].v.tag.value,(unsigned int)thisRuleMatches); } else { // sanity check, can't really happen thisRuleMatches = 0; } } else { if ((inbound)&&(!superAccept)) { thisRuleMatches = 0; - FILTER_TRACE("%u %s %c remote tag %u not found -> 0 (inbound side is strict)",rn,_rtn(rt),(((rules[rn].t & 0x80) != 0) ? '!' : '='),(unsigned int)rules[rn].v.tag.id); } else { // Outbound side is not strict since if we have to match both tags and // we are sending a first packet to a recipient, we probably do not know @@ -621,43 +461,35 @@ static _doZtFilterResult _doZtFilter( // once we get their tag. If we are a tee/redirect target we are also // not strict since we likely do not have these tags. thisRuleMatches = 1; - FILTER_TRACE("%u %s %c remote tag %u not found -> 1 (outbound side and TEE/REDIRECT targets are not strict)",rn,_rtn(rt),(((rules[rn].t & 0x80) != 0) ? '!' : '='),(unsigned int)rules[rn].v.tag.id); } } } else { thisRuleMatches = 0; - FILTER_TRACE("%u %s %c local tag %u not found -> 0",rn,_rtn(rt),(((rules[rn].t & 0x80) != 0) ? '!' : '='),(unsigned int)rules[rn].v.tag.id); } } break; case ZT_NETWORK_RULE_MATCH_TAG_SENDER: case ZT_NETWORK_RULE_MATCH_TAG_RECEIVER: { if (superAccept) { thisRuleMatches = 1; - FILTER_TRACE("%u %s %c we are a TEE/REDIRECT target -> 1",rn,_rtn(rt),(((rules[rn].t & 0x80) != 0) ? '!' : '=')); } else if ( ((rt == ZT_NETWORK_RULE_MATCH_TAG_SENDER)&&(inbound)) || ((rt == ZT_NETWORK_RULE_MATCH_TAG_RECEIVER)&&(!inbound)) ) { const Tag *const remoteTag = ((membership) ? membership->getTag(nconf,rules[rn].v.tag.id) : (const Tag *)0); if (remoteTag) { thisRuleMatches = (uint8_t)(remoteTag->value() == rules[rn].v.tag.value); - FILTER_TRACE("%u %s %c TAG %u %.8x == %.8x -> %u",rn,_rtn(rt),(((rules[rn].t & 0x80) != 0) ? '!' : '='),(unsigned int)rules[rn].v.tag.id,remoteTag->value(),(unsigned int)rules[rn].v.tag.value,(unsigned int)thisRuleMatches); } else { if (rt == ZT_NETWORK_RULE_MATCH_TAG_RECEIVER) { // If we are checking the receiver and this is an outbound packet, we // can't be strict since we may not yet know the receiver's tag. thisRuleMatches = 1; - FILTER_TRACE("%u %s %c (inbound) remote tag %u not found -> 1 (outbound receiver match is not strict)",rn,_rtn(rt),(((rules[rn].t & 0x80) != 0) ? '!' : '='),(unsigned int)rules[rn].v.tag.id); } else { thisRuleMatches = 0; - FILTER_TRACE("%u %s %c (inbound) remote tag %u not found -> 0",rn,_rtn(rt),(((rules[rn].t & 0x80) != 0) ? '!' : '='),(unsigned int)rules[rn].v.tag.id); } } } else { // sender and outbound or receiver and inbound const Tag *const localTag = std::lower_bound(&(nconf.tags[0]),&(nconf.tags[nconf.tagCount]),rules[rn].v.tag.id,Tag::IdComparePredicate()); if ((localTag != &(nconf.tags[nconf.tagCount]))&&(localTag->id() == rules[rn].v.tag.id)) { thisRuleMatches = (uint8_t)(localTag->value() == rules[rn].v.tag.value); - FILTER_TRACE("%u %s %c TAG %u %.8x == %.8x -> %u",rn,_rtn(rt),(((rules[rn].t & 0x80) != 0) ? '!' : '='),(unsigned int)rules[rn].v.tag.id,localTag->value(),(unsigned int)rules[rn].v.tag.value,(unsigned int)thisRuleMatches); } else { thisRuleMatches = 0; - FILTER_TRACE("%u %s %c local tag %u not found -> 0",rn,_rtn(rt),(((rules[rn].t & 0x80) != 0) ? '!' : '='),(unsigned int)rules[rn].v.tag.id); } } } break; @@ -669,6 +501,8 @@ static _doZtFilterResult _doZtFilter( break; } + rrl.log(rn,thisRuleMatches,thisSetMatches); + if ((rules[rn].t & 0x40)) thisSetMatches |= (thisRuleMatches ^ ((rules[rn].t >> 7) & 1)); else thisSetMatches &= (thisRuleMatches ^ ((rules[rn].t >> 7) & 1)); @@ -761,33 +595,34 @@ bool Network::filterOutgoingPacket( const uint64_t now = RR->node->now(); Address ztFinalDest(ztDest); int localCapabilityIndex = -1; - bool accept = false; + int accept = 0; + Trace::RuleResultLog rrl,crrl; + Address cc; + unsigned int ccLength = 0; + bool ccWatch = false; Mutex::Lock _l(_lock); Membership *const membership = (ztDest) ? _memberships.get(ztDest) : (Membership *)0; - Address cc; - unsigned int ccLength = 0; - bool ccWatch = false; - switch(_doZtFilter(RR,_config,membership,false,ztSource,ztFinalDest,macSource,macDest,frameData,frameLen,etherType,vlanId,_config.rules,_config.ruleCount,cc,ccLength,ccWatch)) { + switch(_doZtFilter(RR,rrl,_config,membership,false,ztSource,ztFinalDest,macSource,macDest,frameData,frameLen,etherType,vlanId,_config.rules,_config.ruleCount,cc,ccLength,ccWatch)) { - case DOZTFILTER_NO_MATCH: + case DOZTFILTER_NO_MATCH: { for(unsigned int c=0;c<_config.capabilityCount;++c) { ztFinalDest = ztDest; // sanity check, shouldn't be possible if there was no match Address cc2; unsigned int ccLength2 = 0; bool ccWatch2 = false; - switch (_doZtFilter(RR,_config,membership,false,ztSource,ztFinalDest,macSource,macDest,frameData,frameLen,etherType,vlanId,_config.capabilities[c].rules(),_config.capabilities[c].ruleCount(),cc2,ccLength2,ccWatch2)) { + switch (_doZtFilter(RR,crrl,_config,membership,false,ztSource,ztFinalDest,macSource,macDest,frameData,frameLen,etherType,vlanId,_config.capabilities[c].rules(),_config.capabilities[c].ruleCount(),cc2,ccLength2,ccWatch2)) { case DOZTFILTER_NO_MATCH: case DOZTFILTER_DROP: // explicit DROP in a capability just terminates its evaluation and is an anti-pattern break; case DOZTFILTER_REDIRECT: // interpreted as ACCEPT but ztFinalDest will have been changed in _doZtFilter() case DOZTFILTER_ACCEPT: - case DOZTFILTER_SUPER_ACCEPT: // no difference in behavior on outbound side + case DOZTFILTER_SUPER_ACCEPT: // no difference in behavior on outbound side in capabilities localCapabilityIndex = (int)c; - accept = true; + accept = 1; if ((!noTee)&&(cc2)) { Membership &m2 = _membership(cc2); @@ -809,15 +644,20 @@ bool Network::filterOutgoingPacket( if (accept) break; } - break; + } break; case DOZTFILTER_DROP: + if (_config.remoteTraceTarget) + RR->t->networkFilter(*this,rrl,(Trace::RuleResultLog *)0,(Capability *)0,ztSource,ztDest,macSource,macDest,frameData,frameLen,etherType,vlanId,noTee,false,0); return false; case DOZTFILTER_REDIRECT: // interpreted as ACCEPT but ztFinalDest will have been changed in _doZtFilter() case DOZTFILTER_ACCEPT: - case DOZTFILTER_SUPER_ACCEPT: // no difference in behavior on outbound side - accept = true; + accept = 1; + break; + + case DOZTFILTER_SUPER_ACCEPT: + accept = 2; break; } @@ -854,11 +694,17 @@ bool Network::filterOutgoingPacket( outp.compress(); RR->sw->send(tPtr,outp,true); + if (_config.remoteTraceTarget) + RR->t->networkFilter(*this,rrl,(localCapabilityIndex >= 0) ? &crrl : (Trace::RuleResultLog *)0,(localCapabilityIndex >= 0) ? &(_config.capabilities[localCapabilityIndex]) : (Capability *)0,ztSource,ztDest,macSource,macDest,frameData,frameLen,etherType,vlanId,noTee,false,0); return false; // DROP locally, since we redirected } else { + if (_config.remoteTraceTarget) + RR->t->networkFilter(*this,rrl,(localCapabilityIndex >= 0) ? &crrl : (Trace::RuleResultLog *)0,(localCapabilityIndex >= 0) ? &(_config.capabilities[localCapabilityIndex]) : (Capability *)0,ztSource,ztDest,macSource,macDest,frameData,frameLen,etherType,vlanId,noTee,false,1); return true; } } else { + if (_config.remoteTraceTarget) + RR->t->networkFilter(*this,rrl,(localCapabilityIndex >= 0) ? &crrl : (Trace::RuleResultLog *)0,(localCapabilityIndex >= 0) ? &(_config.capabilities[localCapabilityIndex]) : (Capability *)0,ztSource,ztDest,macSource,macDest,frameData,frameLen,etherType,vlanId,noTee,false,0); return false; } } @@ -875,26 +721,27 @@ int Network::filterIncomingPacket( const unsigned int vlanId) { Address ztFinalDest(ztDest); + Trace::RuleResultLog rrl,crrl; int accept = 0; + Address cc; + unsigned int ccLength = 0; + bool ccWatch = false; + const Capability *c = (Capability *)0; Mutex::Lock _l(_lock); Membership &membership = _membership(sourcePeer->address()); - Address cc; - unsigned int ccLength = 0; - bool ccWatch = false; - switch (_doZtFilter(RR,_config,&membership,true,sourcePeer->address(),ztFinalDest,macSource,macDest,frameData,frameLen,etherType,vlanId,_config.rules,_config.ruleCount,cc,ccLength,ccWatch)) { + switch (_doZtFilter(RR,rrl,_config,&membership,true,sourcePeer->address(),ztFinalDest,macSource,macDest,frameData,frameLen,etherType,vlanId,_config.rules,_config.ruleCount,cc,ccLength,ccWatch)) { case DOZTFILTER_NO_MATCH: { Membership::CapabilityIterator mci(membership,_config); - const Capability *c; while ((c = mci.next())) { ztFinalDest = ztDest; // sanity check, should be unmodified if there was no match Address cc2; unsigned int ccLength2 = 0; bool ccWatch2 = false; - switch(_doZtFilter(RR,_config,&membership,true,sourcePeer->address(),ztFinalDest,macSource,macDest,frameData,frameLen,etherType,vlanId,c->rules(),c->ruleCount(),cc2,ccLength2,ccWatch2)) { + switch(_doZtFilter(RR,crrl,_config,&membership,true,sourcePeer->address(),ztFinalDest,macSource,macDest,frameData,frameLen,etherType,vlanId,c->rules(),c->ruleCount(),cc2,ccLength2,ccWatch2)) { case DOZTFILTER_NO_MATCH: case DOZTFILTER_DROP: // explicit DROP in a capability just terminates its evaluation and is an anti-pattern break; @@ -927,6 +774,8 @@ int Network::filterIncomingPacket( } break; case DOZTFILTER_DROP: + if (_config.remoteTraceTarget) + RR->t->networkFilter(*this,rrl,(Trace::RuleResultLog *)0,(Capability *)0,sourcePeer->address(),ztDest,macSource,macDest,frameData,frameLen,etherType,vlanId,false,true,0); return 0; // DROP case DOZTFILTER_REDIRECT: // interpreted as ACCEPT but ztFinalDest will have been changed in _doZtFilter() @@ -966,10 +815,14 @@ int Network::filterIncomingPacket( outp.compress(); RR->sw->send(tPtr,outp,true); + if (_config.remoteTraceTarget) + RR->t->networkFilter(*this,rrl,(c) ? &crrl : (Trace::RuleResultLog *)0,c,sourcePeer->address(),ztDest,macSource,macDest,frameData,frameLen,etherType,vlanId,false,true,0); return 0; // DROP locally, since we redirected } } + if (_config.remoteTraceTarget) + RR->t->networkFilter(*this,rrl,(c) ? &crrl : (Trace::RuleResultLog *)0,c,sourcePeer->address(),ztDest,macSource,macDest,frameData,frameLen,etherType,vlanId,false,true,accept); return accept; } @@ -1025,15 +878,10 @@ uint64_t Network::handleConfigChunk(void *tPtr,const uint64_t packetId,const Add totalLength = chunk.at<uint32_t>(ptr); ptr += 4; chunkIndex = chunk.at<uint32_t>(ptr); ptr += 4; - if (((chunkIndex + chunkLen) > totalLength)||(totalLength >= ZT_NETWORKCONFIG_DICT_CAPACITY)) { // >= since we need room for a null at the end - TRACE("discarded chunk from %s: invalid length or length overflow",source.toString().c_str()); + if (((chunkIndex + chunkLen) > totalLength)||(totalLength >= ZT_NETWORKCONFIG_DICT_CAPACITY)) // >= since we need room for a null at the end return 0; - } - - if ((chunk[ptr] != 1)||(chunk.at<uint16_t>(ptr + 1) != ZT_C25519_SIGNATURE_LEN)) { - TRACE("discarded chunk from %s: unrecognized signature type",source.toString().c_str()); + if ((chunk[ptr] != 1)||(chunk.at<uint16_t>(ptr + 1) != ZT_C25519_SIGNATURE_LEN)) return 0; - } const uint8_t *sig = reinterpret_cast<const uint8_t *>(chunk.field(ptr + 3,ZT_C25519_SIGNATURE_LEN)); // We can use the signature, which is unique per chunk, to get a per-chunk ID for local deduplication use @@ -1058,14 +906,10 @@ uint64_t Network::handleConfigChunk(void *tPtr,const uint64_t packetId,const Add // If it's not a duplicate, check chunk signature const Identity controllerId(RR->topology->getIdentity(tPtr,controller())); - if (!controllerId) { // we should always have the controller identity by now, otherwise how would we have queried it the first time? - TRACE("unable to verify chunk from %s: don't have controller identity",source.toString().c_str()); + if (!controllerId) // we should always have the controller identity by now, otherwise how would we have queried it the first time? return 0; - } - if (!controllerId.verify(chunk.field(start,ptr - start),ptr - start,sig,ZT_C25519_SIGNATURE_LEN)) { - TRACE("discarded chunk from %s: signature check failed",source.toString().c_str()); + if (!controllerId.verify(chunk.field(start,ptr - start),ptr - start,sig,ZT_C25519_SIGNATURE_LEN)) return 0; - } // New properly verified chunks can be flooded "virally" through the network if (fastPropagate) { @@ -1095,7 +939,7 @@ uint64_t Network::handleConfigChunk(void *tPtr,const uint64_t packetId,const Add c = &(_incomingConfigChunks[i]); } } else { - TRACE("discarded single-chunk unsigned legacy config: this is only allowed if the sender is the controller itself"); + // Single-chunk unsigned legacy configs are only allowed from the controller itself return 0; } @@ -1188,9 +1032,7 @@ int Network::setConfiguration(void *tPtr,const NetworkConfig &nconf,bool saveToD } return 2; // OK and configuration has changed - } catch ( ... ) { - TRACE("ignored invalid configuration for network %.16llx",(unsigned long long)_id); - } + } catch ( ... ) {} // ignore invalid configs return 0; } @@ -1293,6 +1135,8 @@ void Network::requestConfiguration(void *tPtr) rmd.add(ZT_NETWORKCONFIG_REQUEST_METADATA_KEY_FLAGS,(uint64_t)0); rmd.add(ZT_NETWORKCONFIG_REQUEST_METADATA_KEY_RULES_ENGINE_REV,(uint64_t)ZT_RULES_ENGINE_REVISION); + RR->t->networkConfigRequestSent(*this,ctrl); + if (ctrl == RR->identity.address()) { if (RR->localNetworkController) { RR->localNetworkController->request(_id,InetAddress(),0xffffffffffffffffULL,RR->identity,rmd); @@ -1302,8 +1146,6 @@ void Network::requestConfiguration(void *tPtr) return; } - TRACE("requesting netconf for network %.16llx from controller %s",(unsigned long long)_id,ctrl.toString().c_str()); - Packet outp(ctrl,RR->identity.address(),Packet::VERB_NETWORK_CONFIG_REQUEST); outp.append((uint64_t)_id); const unsigned int rmdSize = rmd.sizeBytes(); @@ -1337,9 +1179,7 @@ bool Network::gate(void *tPtr,const SharedPtr<Peer> &peer) return true; } } - } catch ( ... ) { - TRACE("gate() check failed for peer %s: unexpected exception",peer->address().toString().c_str()); - } + } catch ( ... ) {} return false; } diff --git a/node/NetworkConfig.cpp b/node/NetworkConfig.cpp index e5929923..0bf4bc19 100644 --- a/node/NetworkConfig.cpp +++ b/node/NetworkConfig.cpp @@ -47,6 +47,7 @@ bool NetworkConfig::toDictionary(Dictionary<ZT_NETWORKCONFIG_DICT_CAPACITY> &d,b if (!d.add(ZT_NETWORKCONFIG_DICT_KEY_CREDENTIAL_TIME_MAX_DELTA,this->credentialTimeMaxDelta)) return false; if (!d.add(ZT_NETWORKCONFIG_DICT_KEY_REVISION,this->revision)) return false; if (!d.add(ZT_NETWORKCONFIG_DICT_KEY_ISSUED_TO,this->issuedTo)) return false; + if (!d.add(ZT_NETWORKCONFIG_DICT_KEY_REMOTE_TRACE_TARGET,this->remoteTraceTarget)) return false; if (!d.add(ZT_NETWORKCONFIG_DICT_KEY_FLAGS,this->flags)) return false; if (!d.add(ZT_NETWORKCONFIG_DICT_KEY_MULTICAST_LIMIT,(uint64_t)this->multicastLimit)) return false; if (!d.add(ZT_NETWORKCONFIG_DICT_KEY_TYPE,(uint64_t)this->type)) return false; @@ -217,6 +218,7 @@ bool NetworkConfig::fromDictionary(const Dictionary<ZT_NETWORKCONFIG_DICT_CAPACI delete tmp; return false; } + this->remoteTraceTarget = d.getUI(ZT_NETWORKCONFIG_DICT_KEY_REMOTE_TRACE_TARGET); this->multicastLimit = (unsigned int)d.getUI(ZT_NETWORKCONFIG_DICT_KEY_MULTICAST_LIMIT,0); d.get(ZT_NETWORKCONFIG_DICT_KEY_NAME,this->name,sizeof(this->name)); diff --git a/node/NetworkConfig.hpp b/node/NetworkConfig.hpp index fdd078d5..8b3b3619 100644 --- a/node/NetworkConfig.hpp +++ b/node/NetworkConfig.hpp @@ -159,6 +159,8 @@ namespace ZeroTier { #define ZT_NETWORKCONFIG_DICT_KEY_REVISION "r" // address of member #define ZT_NETWORKCONFIG_DICT_KEY_ISSUED_TO "id" +// remote trace target +#define ZT_NETWORKCONFIG_DICT_KEY_REMOTE_TRACE_TARGET "tt" // flags(hex) #define ZT_NETWORKCONFIG_DICT_KEY_FLAGS "f" // integer(hex) @@ -463,6 +465,11 @@ public: Address issuedTo; /** + * If non-NULL, remote traces related to this network are sent here + */ + Address remoteTraceTarget; + + /** * Flags (64-bit) */ uint64_t flags; diff --git a/node/Node.cpp b/node/Node.cpp index e28accee..c54ca450 100644 --- a/node/Node.cpp +++ b/node/Node.cpp @@ -46,6 +46,7 @@ #include "Identity.hpp" #include "SelfAwareness.hpp" #include "Network.hpp" +#include "Trace.hpp" namespace ZeroTier { @@ -108,6 +109,7 @@ Node::Node(void *uptr,void *tptr,const struct ZT_Node_Callbacks *callbacks,uint6 } try { + RR->t = new Trace(RR); RR->sw = new Switch(RR); RR->mc = new Multicaster(RR); RR->topology = new Topology(RR,tptr); @@ -133,6 +135,7 @@ Node::~Node() delete RR->topology; delete RR->mc; delete RR->sw; + delete RR->t; } ZT_ResultCode Node::processWirePacket( diff --git a/node/Node.hpp b/node/Node.hpp index 40903f7c..57b99fe9 100644 --- a/node/Node.hpp +++ b/node/Node.hpp @@ -48,13 +48,6 @@ #include "NetworkController.hpp" #include "Hashtable.hpp" -#undef TRACE -#ifdef ZT_TRACE -#define TRACE(f,...) RR->node->postTrace(__FILE__,__LINE__,f,##__VA_ARGS__) -#else -#define TRACE(f,...) {} -#endif - // Bit mask for "expecting reply" hash #define ZT_EXPECTING_REPLIES_BUCKET_MASK1 255 #define ZT_EXPECTING_REPLIES_BUCKET_MASK2 31 diff --git a/node/OutboundMulticast.cpp b/node/OutboundMulticast.cpp index a2341ffd..04ba2c2a 100644 --- a/node/OutboundMulticast.cpp +++ b/node/OutboundMulticast.cpp @@ -65,18 +65,6 @@ void OutboundMulticast::init( if (gatherLimit) flags |= 0x02; - /* - TRACE(">>MC %.16llx INIT %.16llx/%s limit %u gatherLimit %u from %s to %s length %u", - (unsigned long long)this, - nwid, - dest.toString().c_str(), - limit, - gatherLimit, - (src) ? src.toString().c_str() : MAC(RR->identity.address(),nwid).toString().c_str(), - dest.toString().c_str(), - len); - */ - _packet.setSource(RR->identity.address()); _packet.setVerb(Packet::VERB_MULTICAST_FRAME); _packet.append((uint64_t)nwid); @@ -98,7 +86,6 @@ void OutboundMulticast::sendOnly(const RuntimeEnvironment *RR,void *tPtr,const A const SharedPtr<Network> nw(RR->node->network(_nwid)); const Address toAddr2(toAddr); if ((nw)&&(nw->filterOutgoingPacket(tPtr,true,RR->identity.address(),toAddr2,_macSrc,_macDest,_frameData,_frameLen,_etherType,0))) { - //TRACE(">>MC %.16llx -> %s",(unsigned long long)this,toAddr.toString().c_str()); _packet.newInitializationVector(); _packet.setDestination(toAddr2); RR->node->expectReplyTo(_packet.packetId()); diff --git a/node/Packet.cpp b/node/Packet.cpp index 6e1b36ac..d3f7dfd6 100644 --- a/node/Packet.cpp +++ b/node/Packet.cpp @@ -1061,50 +1061,6 @@ static inline int LZ4_decompress_safe(const char* source, char* dest, int compre const unsigned char Packet::ZERO_KEY[32] = { 0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0 }; -#ifdef ZT_TRACE - -const char *Packet::verbString(Verb v) -{ - switch(v) { - case VERB_NOP: return "NOP"; - case VERB_HELLO: return "HELLO"; - case VERB_ERROR: return "ERROR"; - case VERB_OK: return "OK"; - case VERB_WHOIS: return "WHOIS"; - case VERB_RENDEZVOUS: return "RENDEZVOUS"; - case VERB_FRAME: return "FRAME"; - case VERB_EXT_FRAME: return "EXT_FRAME"; - case VERB_ECHO: return "ECHO"; - case VERB_MULTICAST_LIKE: return "MULTICAST_LIKE"; - case VERB_NETWORK_CREDENTIALS: return "NETWORK_CREDENTIALS"; - case VERB_NETWORK_CONFIG_REQUEST: return "NETWORK_CONFIG_REQUEST"; - case VERB_NETWORK_CONFIG: return "NETWORK_CONFIG"; - case VERB_MULTICAST_GATHER: return "MULTICAST_GATHER"; - case VERB_MULTICAST_FRAME: return "MULTICAST_FRAME"; - case VERB_PUSH_DIRECT_PATHS: return "PUSH_DIRECT_PATHS"; - case VERB_USER_MESSAGE: return "USER_MESSAGE"; - } - return "(unknown)"; -} - -const char *Packet::errorString(ErrorCode e) -{ - switch(e) { - case ERROR_NONE: return "NONE"; - case ERROR_INVALID_REQUEST: return "INVALID_REQUEST"; - case ERROR_BAD_PROTOCOL_VERSION: return "BAD_PROTOCOL_VERSION"; - case ERROR_OBJ_NOT_FOUND: return "OBJECT_NOT_FOUND"; - case ERROR_IDENTITY_COLLISION: return "IDENTITY_COLLISION"; - case ERROR_UNSUPPORTED_OPERATION: return "UNSUPPORTED_OPERATION"; - case ERROR_NEED_MEMBERSHIP_CERTIFICATE: return "NEED_MEMBERSHIP_CERTIFICATE"; - case ERROR_NETWORK_ACCESS_DENIED_: return "NETWORK_ACCESS_DENIED"; - case ERROR_UNWANTED_MULTICAST: return "UNWANTED_MULTICAST"; - } - return "(unknown)"; -} - -#endif // ZT_TRACE - void Packet::armor(const void *key,bool encryptPayload,unsigned int counter) { uint8_t mangledKey[32]; diff --git a/node/Packet.hpp b/node/Packet.hpp index a76d4180..4941e96a 100644 --- a/node/Packet.hpp +++ b/node/Packet.hpp @@ -42,12 +42,6 @@ #include "Utils.hpp" #include "Buffer.hpp" -//#ifdef ZT_USE_SYSTEM_LZ4 -//#include <lz4.h> -//#else -//#include "../ext/lz4/lz4.h" -//#endif - /** * Protocol version -- incremented only for major changes * @@ -969,7 +963,27 @@ public: * ZeroTier, Inc. itself. We recommend making up random ones for your own * implementations. */ - VERB_USER_MESSAGE = 0x14 + VERB_USER_MESSAGE = 0x14, + + /** + * A trace for remote debugging or diagnostics: + * <[8] 64-bit instance ID> + * <[2] 16-bit length of Dictionary> + * <[...] dictionary containing trace information> + * + * This message contains a remote trace event. Remote trace events can + * be sent to observers configured at the network level for those that + * pertain directly to actiity on a network, or to global observers if + * locally configured. + * + * The instance ID is a random 64-bit value generated by each ZeroTier + * node on startup. This is helpful in identifying traces from different + * members of a cluster. + * + * The Dictionary serialization format is the same as used for network + * configurations. The maximum size of a trace is 10000 bytes. + */ + VERB_REMOTE_TRACE = 0x15 }; /** @@ -1005,11 +1019,6 @@ public: ERROR_UNWANTED_MULTICAST = 0x08 }; -#ifdef ZT_TRACE - static const char *verbString(Verb v); - static const char *errorString(ErrorCode e); -#endif - template<unsigned int C2> Packet(const Buffer<C2> &b) : Buffer<ZT_PROTO_MAX_PACKET_LENGTH>(b) diff --git a/node/Peer.cpp b/node/Peer.cpp index e16540b3..79a4bc90 100644 --- a/node/Peer.cpp +++ b/node/Peer.cpp @@ -33,6 +33,7 @@ #include "Network.hpp" #include "SelfAwareness.hpp" #include "Packet.hpp" +#include "Trace.hpp" namespace ZeroTier { @@ -168,22 +169,25 @@ void Peer::received( if ( (!pathAlreadyKnown) && (RR->node->shouldUsePathForZeroTierTraffic(tPtr,_id.address(),path->localSocket(),path->address())) ) { Mutex::Lock _l(_paths_m); - _PeerPath *potentialNewPeerPath = (_PeerPath *)0; + + _PeerPath *replacablePath = (_PeerPath *)0; if (path->address().ss_family == AF_INET) { if ( ( (!_v4Path.p) || (!_v4Path.p->alive(now)) || (path->preferenceRank() >= _v4Path.p->preferenceRank()) ) && ( (now - _v4Path.sticky) > ZT_PEER_PATH_EXPIRATION ) ) { - potentialNewPeerPath = &_v4Path; + replacablePath = &_v4Path; } } else if (path->address().ss_family == AF_INET6) { if ( ( (!_v6Path.p) || (!_v6Path.p->alive(now)) || (path->preferenceRank() >= _v6Path.p->preferenceRank()) ) && ( (now - _v6Path.sticky) > ZT_PEER_PATH_EXPIRATION ) ) { - potentialNewPeerPath = &_v6Path; + replacablePath = &_v6Path; } } - if (potentialNewPeerPath) { + + if (replacablePath) { if (verb == Packet::VERB_OK) { - potentialNewPeerPath->lr = now; - potentialNewPeerPath->p = path; + RR->t->peerLearnedNewPath(*this,replacablePath->p,path,packetId); + replacablePath->lr = now; + replacablePath->p = path; } else { - TRACE("got %s via unknown path %s(%s), confirming...",Packet::verbString(verb),_id.address().toString().c_str(),path->address().toString().c_str()); + RR->t->peerConfirmingUnknownPath(*this,path,packetId,verb); attemptToContactAt(tPtr,path->localSocket(),path->address(),now,true,path->nextOutgoingCounter()); path->sent(now); } @@ -211,16 +215,6 @@ void Peer::received( } if (pathsToPush.size() > 0) { -#ifdef ZT_TRACE - std::string ps; - for(std::vector<InetAddress>::const_iterator p(pathsToPush.begin());p!=pathsToPush.end();++p) { - if (ps.length() > 0) - ps.push_back(','); - ps.append(p->toString()); - } - TRACE("pushing %u direct paths to %s: %s",(unsigned int)pathsToPush.size(),_id.address().toString().c_str(),ps.c_str()); -#endif - std::vector<InetAddress>::const_iterator p(pathsToPush.begin()); while (p != pathsToPush.end()) { Packet outp(_id.address(),RR->identity.address(),Packet::VERB_PUSH_DIRECT_PATHS); @@ -424,16 +418,27 @@ bool Peer::doPingAndKeepalive(void *tPtr,uint64_t now,int inetAddressFamily) void Peer::redirect(void *tPtr,const int64_t localSocket,const InetAddress &remoteAddress,const uint64_t now) { - Mutex::Lock _l(_paths_m); - SharedPtr<Path> p(RR->topology->getPath(localSocket,remoteAddress)); - attemptToContactAt(tPtr,localSocket,remoteAddress,now,true,p->nextOutgoingCounter()); - if (remoteAddress.ss_family == AF_INET) { - _v4Path.p = p; - _v4Path.sticky = now; - } else if (remoteAddress.ss_family == AF_INET6) { - _v6Path.p = p; - _v6Path.sticky = now; + if ((remoteAddress.ss_family != AF_INET)&&(remoteAddress.ss_family != AF_INET6)) // sanity check + return; + + SharedPtr<Path> op; + SharedPtr<Path> np(RR->topology->getPath(localSocket,remoteAddress)); + attemptToContactAt(tPtr,localSocket,remoteAddress,now,true,np->nextOutgoingCounter()); + + { + Mutex::Lock _l(_paths_m); + if (remoteAddress.ss_family == AF_INET) { + op = _v4Path.p; + _v4Path.p = np; + _v4Path.sticky = now; + } else if (remoteAddress.ss_family == AF_INET6) { + op = _v6Path.p; + _v6Path.p = np; + _v6Path.sticky = now; + } } + + RR->t->peerRedirected(*this,op,np); } } // namespace ZeroTier diff --git a/node/RuntimeEnvironment.hpp b/node/RuntimeEnvironment.hpp index 94b96d34..0bb78599 100644 --- a/node/RuntimeEnvironment.hpp +++ b/node/RuntimeEnvironment.hpp @@ -42,7 +42,7 @@ class Node; class Multicaster; class NetworkController; class SelfAwareness; -class Cluster; +class Trace; /** * Holds global state for an instance of ZeroTier::Node @@ -93,6 +93,7 @@ public: * These are constant and never null after startup unless indicated. */ + Trace *t; Switch *sw; Multicaster *mc; Topology *topology; diff --git a/node/SelfAwareness.cpp b/node/SelfAwareness.cpp index 3e3397f5..173230fb 100644 --- a/node/SelfAwareness.cpp +++ b/node/SelfAwareness.cpp @@ -39,6 +39,7 @@ #include "Packet.hpp" #include "Peer.hpp" #include "Switch.hpp" +#include "Trace.hpp" // Entry timeout -- make it fairly long since this is just to prevent stale buildup #define ZT_SELFAWARENESS_ENTRY_TIMEOUT 600000 @@ -81,7 +82,7 @@ void SelfAwareness::iam(void *tPtr,const Address &reporter,const int64_t receive if ( (trusted) && ((now - entry.ts) < ZT_SELFAWARENESS_ENTRY_TIMEOUT) && (!entry.mySurface.ipsEqual(myPhysicalAddress)) ) { // Changes to external surface reported by trusted peers causes path reset in this scope - TRACE("physical address %s for scope %u as seen from %s(%s) differs from %s, resetting paths in scope",myPhysicalAddress.toString().c_str(),(unsigned int)scope,reporter.toString().c_str(),reporterPhysicalAddress.toString().c_str(),entry.mySurface.toString().c_str()); + RR->t->resettingPathsInScope(reporter,reporterPhysicalAddress,myPhysicalAddress,scope); entry.mySurface = myPhysicalAddress; entry.ts = now; diff --git a/node/Switch.cpp b/node/Switch.cpp index a77ca89e..2fbd243b 100644 --- a/node/Switch.cpp +++ b/node/Switch.cpp @@ -43,26 +43,10 @@ #include "Peer.hpp" #include "SelfAwareness.hpp" #include "Packet.hpp" +#include "Trace.hpp" namespace ZeroTier { -#ifdef ZT_TRACE -static const char *etherTypeName(const unsigned int etherType) -{ - switch(etherType) { - case ZT_ETHERTYPE_IPV4: return "IPV4"; - case ZT_ETHERTYPE_ARP: return "ARP"; - case ZT_ETHERTYPE_RARP: return "RARP"; - case ZT_ETHERTYPE_ATALK: return "ATALK"; - case ZT_ETHERTYPE_AARP: return "AARP"; - case ZT_ETHERTYPE_IPX_A: return "IPX_A"; - case ZT_ETHERTYPE_IPX_B: return "IPX_B"; - case ZT_ETHERTYPE_IPV6: return "IPV6"; - } - return "UNKNOWN"; -} -#endif // ZT_TRACE - Switch::Switch(const RuntimeEnvironment *renv) : RR(renv), _lastBeaconResponse(0), @@ -123,8 +107,6 @@ void Switch::onRemotePacket(void *tPtr,const int64_t localSocket,const InetAddre if (relayTo) relayTo->sendDirect(tPtr,fragment.data(),fragment.size(),now,true); } - } else { - TRACE("dropped relay [fragment](%s) -> %s, max hops exceeded",fromAddr.toString().c_str(),destination.toString().c_str()); } } else { // Fragment looks like ours @@ -143,7 +125,6 @@ void Switch::onRemotePacket(void *tPtr,const int64_t localSocket,const InetAddre if ((!rq->timestamp)||(rq->packetId != fragmentPacketId)) { // No packet found, so we received a fragment without its head. - //TRACE("fragment (%u/%u) of %.16llx from %s",fragmentNumber + 1,totalFragments,fragmentPacketId,fromAddr.toString().c_str()); rq->timestamp = now; rq->packetId = fragmentPacketId; @@ -153,14 +134,12 @@ void Switch::onRemotePacket(void *tPtr,const int64_t localSocket,const InetAddre rq->complete = false; } else if (!(rq->haveFragments & (1 << fragmentNumber))) { // We have other fragments and maybe the head, so add this one and check - //TRACE("fragment (%u/%u) of %.16llx from %s",fragmentNumber + 1,totalFragments,fragmentPacketId,fromAddr.toString().c_str()); rq->frags[fragmentNumber - 1] = fragment; rq->totalFragments = totalFragments; if (Utils::countBits(rq->haveFragments |= (1 << fragmentNumber)) == totalFragments) { // We have all fragments -- assemble and process full Packet - //TRACE("packet %.16llx is complete, assembling and processing...",fragmentPacketId); for(unsigned int f=1;f<totalFragments;++f) rq->frag0.append(rq->frags[f - 1].payload(),rq->frags[f - 1].payloadLength()); @@ -182,8 +161,6 @@ void Switch::onRemotePacket(void *tPtr,const int64_t localSocket,const InetAddre const Address destination(reinterpret_cast<const uint8_t *>(data) + 8,ZT_ADDRESS_LENGTH); const Address source(reinterpret_cast<const uint8_t *>(data) + 13,ZT_ADDRESS_LENGTH); - //TRACE("<< %.16llx %s -> %s (size: %u)",(unsigned long long)packet->packetId(),source.toString().c_str(),destination.toString().c_str(),packet->size()); - if (source == RR->identity.address()) return; @@ -258,8 +235,6 @@ void Switch::onRemotePacket(void *tPtr,const int64_t localSocket,const InetAddre if (relayTo) relayTo->sendDirect(tPtr,packet.data(),packet.size(),now,true); } - } else { - TRACE("dropped relay %s(%s) -> %s, max hops exceeded",packet.source().toString().c_str(),fromAddr.toString().c_str(),destination.toString().c_str()); } } else if ((reinterpret_cast<const uint8_t *>(data)[ZT_PACKET_IDX_FLAGS] & ZT_PROTO_FLAG_FRAGMENTED) != 0) { // Packet is the head of a fragmented packet series @@ -280,7 +255,6 @@ void Switch::onRemotePacket(void *tPtr,const int64_t localSocket,const InetAddre if ((!rq->timestamp)||(rq->packetId != packetId)) { // If we have no other fragments yet, create an entry and save the head - //TRACE("fragment (0/?) of %.16llx from %s",pid,fromAddr.toString().c_str()); rq->timestamp = now; rq->packetId = packetId; @@ -293,7 +267,6 @@ void Switch::onRemotePacket(void *tPtr,const int64_t localSocket,const InetAddre if ((rq->totalFragments > 1)&&(Utils::countBits(rq->haveFragments |= 1) == rq->totalFragments)) { // We have all fragments -- assemble and process full Packet - //TRACE("packet %.16llx is complete, assembling and processing...",pid); rq->frag0.init(data,len,path,now); for(unsigned int f=1;f<rq->totalFragments;++f) @@ -333,11 +306,7 @@ void Switch::onRemotePacket(void *tPtr,const int64_t localSocket,const InetAddre // -------------------------------------------------------------------- } } - } catch (std::exception &ex) { - TRACE("dropped packet from %s: unexpected exception: %s",fromAddr.toString().c_str(),ex.what()); - } catch ( ... ) { - TRACE("dropped packet from %s: unexpected exception: (unknown)",fromAddr.toString().c_str()); - } + } catch ( ... ) {} // sanity check, should be caught elsewhere } void Switch::onLocalEthernet(void *tPtr,const SharedPtr<Network> &network,const MAC &from,const MAC &to,unsigned int etherType,unsigned int vlanId,const void *data,unsigned int len) @@ -349,7 +318,7 @@ void Switch::onLocalEthernet(void *tPtr,const SharedPtr<Network> &network,const bool fromBridged; if ((fromBridged = (from != network->mac()))) { if (!network->config().permitsBridging(RR->identity.address())) { - TRACE("%.16llx: %s -> %s %s not forwarded, bridging disabled or this peer not a bridge",network->id(),from.toString().c_str(),to.toString().c_str(),etherTypeName(etherType)); + RR->t->outgoingFrameDropped(network,from,to,etherType,vlanId,len,"not a bridge"); return; } } @@ -371,7 +340,7 @@ void Switch::onLocalEthernet(void *tPtr,const SharedPtr<Network> &network,const multicastGroup = MulticastGroup::deriveMulticastGroupForAddressResolution(InetAddress(((const unsigned char *)data) + 24,4,0)); } else if (!network->config().enableBroadcast()) { // Don't transmit broadcasts if this network doesn't want them - TRACE("%.16llx: dropped broadcast since ff:ff:ff:ff:ff:ff is not enabled",network->id()); + RR->t->outgoingFrameDropped(network,from,to,etherType,vlanId,len,"broadcast disabled"); return; } } else if ((etherType == ZT_ETHERTYPE_IPV6)&&(len >= (40 + 8 + 16))) { @@ -424,7 +393,6 @@ void Switch::onLocalEthernet(void *tPtr,const SharedPtr<Network> &network,const if ((v6EmbeddedAddress)&&(v6EmbeddedAddress != RR->identity.address())) { const MAC peerMac(v6EmbeddedAddress,network->id()); - TRACE("IPv6 NDP emulation: %.16llx: forging response for %s/%s",network->id(),v6EmbeddedAddress.toString().c_str(),peerMac.toString().c_str()); uint8_t adv[72]; adv[0] = 0x60; adv[1] = 0x00; adv[2] = 0x00; adv[3] = 0x00; @@ -460,7 +428,7 @@ void Switch::onLocalEthernet(void *tPtr,const SharedPtr<Network> &network,const // Check this after NDP emulation, since that has to be allowed in exactly this case if (network->config().multicastLimit == 0) { - TRACE("%.16llx: dropped multicast: not allowed on network",network->id()); + RR->t->outgoingFrameDropped(network,from,to,etherType,vlanId,len,"multicast disabled"); return; } @@ -471,11 +439,9 @@ void Switch::onLocalEthernet(void *tPtr,const SharedPtr<Network> &network,const if (fromBridged) network->learnBridgedMulticastGroup(tPtr,multicastGroup,RR->node->now()); - //TRACE("%.16llx: MULTICAST %s -> %s %s %u",network->id(),from.toString().c_str(),multicastGroup.toString().c_str(),etherTypeName(etherType),len); - // First pass sets noTee to false, but noTee is set to true in OutboundMulticast to prevent duplicates. if (!network->filterOutgoingPacket(tPtr,false,RR->identity.address(),Address(),from,to,(const uint8_t *)data,len,etherType,vlanId)) { - TRACE("%.16llx: %s -> %s %s packet not sent: filterOutgoingPacket() returned false",network->id(),from.toString().c_str(),to.toString().c_str(),etherTypeName(etherType)); + RR->t->outgoingFrameDropped(network,from,to,etherType,vlanId,len,"filter blocked"); return; } @@ -501,7 +467,7 @@ void Switch::onLocalEthernet(void *tPtr,const SharedPtr<Network> &network,const SharedPtr<Peer> toPeer(RR->topology->getPeer(tPtr,toZT)); if (!network->filterOutgoingPacket(tPtr,false,RR->identity.address(),toZT,from,to,(const uint8_t *)data,len,etherType,vlanId)) { - TRACE("%.16llx: %s -> %s %s packet not sent: filterOutgoingPacket() returned false",network->id(),from.toString().c_str(),to.toString().c_str(),etherTypeName(etherType)); + RR->t->outgoingFrameDropped(network,from,to,etherType,vlanId,len,"filter blocked"); return; } @@ -526,7 +492,6 @@ void Switch::onLocalEthernet(void *tPtr,const SharedPtr<Network> &network,const send(tPtr,outp,true); } - //TRACE("%.16llx: UNICAST: %s -> %s etherType==%s(%.4x) vlanId==%u len==%u fromBridged==%d includeCom==%d",network->id(),from.toString().c_str(),to.toString().c_str(),etherTypeName(etherType),etherType,vlanId,len,(int)fromBridged,(int)includeCom); } else { // Destination is bridged behind a remote peer @@ -534,7 +499,7 @@ void Switch::onLocalEthernet(void *tPtr,const SharedPtr<Network> &network,const // for each ZT destination are also done below. This is the same rationale // and design as for multicast. if (!network->filterOutgoingPacket(tPtr,false,RR->identity.address(),Address(),from,to,(const uint8_t *)data,len,etherType,vlanId)) { - TRACE("%.16llx: %s -> %s %s packet not sent: filterOutgoingPacket() returned false",network->id(),from.toString().c_str(),to.toString().c_str(),etherTypeName(etherType)); + RR->t->outgoingFrameDropped(network,from,to,etherType,vlanId,len,"filter blocked"); return; } @@ -583,7 +548,7 @@ void Switch::onLocalEthernet(void *tPtr,const SharedPtr<Network> &network,const outp.compress(); send(tPtr,outp,true); } else { - TRACE("%.16llx: %s -> %s %s packet not sent: filterOutgoingPacket() returned false",network->id(),from.toString().c_str(),to.toString().c_str(),etherTypeName(etherType)); + RR->t->outgoingFrameDropped(network,from,to,etherType,vlanId,len,"filter blocked (bridge replication)"); } } } @@ -591,11 +556,8 @@ void Switch::onLocalEthernet(void *tPtr,const SharedPtr<Network> &network,const void Switch::send(void *tPtr,Packet &packet,bool encrypt) { - if (packet.destination() == RR->identity.address()) { - TRACE("BUG: caught attempt to send() to self, ignored"); + if (packet.destination() == RR->identity.address()) return; - } - if (!_trySend(tPtr,packet,encrypt)) { Mutex::Lock _l(_txQueue_m); _txQueue.push_back(TXQueueEntry(packet.destination(),RR->node->now(),packet,encrypt)); @@ -604,13 +566,8 @@ void Switch::send(void *tPtr,Packet &packet,bool encrypt) void Switch::requestWhois(void *tPtr,const Address &addr) { -#ifdef ZT_TRACE - if (addr == RR->identity.address()) { - fprintf(stderr,"FATAL BUG: Switch::requestWhois() caught attempt to WHOIS self" ZT_EOL_S); - abort(); - } -#endif - + if (addr == RR->identity.address()) + return; bool inserted = false; { Mutex::Lock _l(_outstandingWhoisRequests_m); @@ -670,12 +627,10 @@ unsigned long Switch::doTimerTasks(void *tPtr,uint64_t now) const unsigned long since = (unsigned long)(now - r->lastSent); if (since >= ZT_WHOIS_RETRY_DELAY) { if (r->retries >= ZT_MAX_WHOIS_RETRIES) { - TRACE("WHOIS %s timed out",a->toString().c_str()); _outstandingWhoisRequests.erase(*a); } else { r->lastSent = now; r->peersConsulted[r->retries] = _sendWhoisRequest(tPtr,*a,r->peersConsulted,(r->retries > 1) ? r->retries : 0); - TRACE("WHOIS %s (retry %u)",a->toString().c_str(),r->retries); ++r->retries; nextDelay = std::min(nextDelay,(unsigned long)ZT_WHOIS_RETRY_DELAY); } @@ -691,7 +646,7 @@ unsigned long Switch::doTimerTasks(void *tPtr,uint64_t now) if (_trySend(tPtr,txi->packet,txi->encrypt)) _txQueue.erase(txi++); else if ((now - txi->creationTime) > ZT_TRANSMIT_QUEUE_TIMEOUT) { - TRACE("TX %s -> %s timed out",txi->packet.source().toString().c_str(),txi->packet.destination().toString().c_str()); + RR->t->txTimedOut(txi->dest); _txQueue.erase(txi++); } else ++txi; } diff --git a/node/Topology.cpp b/node/Topology.cpp index e7bbdfae..edca0180 100644 --- a/node/Topology.cpp +++ b/node/Topology.cpp @@ -90,11 +90,6 @@ Topology::Topology(const RuntimeEnvironment *renv,void *tPtr) : SharedPtr<Peer> Topology::addPeer(void *tPtr,const SharedPtr<Peer> &peer) { -#ifdef ZT_TRACE - if ((!peer)||(peer->address() == RR->identity.address())) - return SharedPtr<Peer>(); -#endif - SharedPtr<Peer> np; { Mutex::Lock _l(_peers_m); @@ -103,16 +98,13 @@ SharedPtr<Peer> Topology::addPeer(void *tPtr,const SharedPtr<Peer> &peer) hp = peer; np = hp; } - return np; } SharedPtr<Peer> Topology::getPeer(void *tPtr,const Address &zta) { - if (zta == RR->identity.address()) { - TRACE("BUG: ignored attempt to getPeer() for self, returned NULL"); + if (zta == RR->identity.address()) return SharedPtr<Peer>(); - } { Mutex::Lock _l(_peers_m); diff --git a/node/Topology.hpp b/node/Topology.hpp index 5f3e2da1..30e58abc 100644 --- a/node/Topology.hpp +++ b/node/Topology.hpp @@ -330,12 +330,6 @@ public: Address *a = (Address *)0; SharedPtr<Peer> *p = (SharedPtr<Peer> *)0; while (i.next(a,p)) { -#ifdef ZT_TRACE - if (!(*p)) { - fprintf(stderr,"FATAL BUG: eachPeer() caught NULL peer for %s -- peer pointers in Topology should NEVER be NULL" ZT_EOL_S,a->toString().c_str()); - abort(); - } -#endif f(*this,*((const SharedPtr<Peer> *)p)); } } diff --git a/node/Trace.cpp b/node/Trace.cpp new file mode 100644 index 00000000..6b68cfe7 --- /dev/null +++ b/node/Trace.cpp @@ -0,0 +1,197 @@ +/* + * ZeroTier One - Network Virtualization Everywhere + * Copyright (C) 2011-2017 ZeroTier, Inc. https://www.zerotier.com/ + * + * This program is free software: you can redistribute it and/or modify + * it under the terms of the GNU General Public License as published by + * the Free Software Foundation, either version 3 of the License, or + * (at your option) any later version. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * GNU General Public License for more details. + * + * You should have received a copy of the GNU General Public License + * along with this program. If not, see <http://www.gnu.org/licenses/>. + * + * -- + * + * You can be released from the requirements of the license by purchasing + * a commercial license. Buying such a license is mandatory as soon as you + * develop commercial closed-source software that incorporates or links + * directly against ZeroTier software without disclosing the source code + * of your own application. + */ + +#include "Trace.hpp" +#include "RuntimeEnvironment.hpp" +#include "Switch.hpp" +#include "Node.hpp" +#include "Utils.hpp" + +namespace ZeroTier { + +#ifdef ZT_TRACE +static const char *packetVerbString(Packet::Verb v) +{ + switch(v) { + case Packet::VERB_NOP: return "NOP"; + case Packet::VERB_HELLO: return "HELLO"; + case Packet::Packet::VERB_ERROR: return "ERROR"; + case Packet::VERB_OK: return "OK"; + case Packet::VERB_WHOIS: return "WHOIS"; + case Packet::VERB_RENDEZVOUS: return "RENDEZVOUS"; + case Packet::VERB_FRAME: return "FRAME"; + case Packet::VERB_EXT_FRAME: return "EXT_FRAME"; + case Packet::VERB_ECHO: return "ECHO"; + case Packet::VERB_MULTICAST_LIKE: return "MULTICAST_LIKE"; + case Packet::VERB_NETWORK_CREDENTIALS: return "NETWORK_CREDENTIALS"; + case Packet::VERB_NETWORK_CONFIG_REQUEST: return "NETWORK_CONFIG_REQUEST"; + case Packet::VERB_NETWORK_CONFIG: return "NETWORK_CONFIG"; + case Packet::VERB_MULTICAST_GATHER: return "MULTICAST_GATHER"; + case Packet::VERB_MULTICAST_FRAME: return "MULTICAST_FRAME"; + case Packet::VERB_PUSH_DIRECT_PATHS: return "PUSH_DIRECT_PATHS"; + case Packet::VERB_USER_MESSAGE: return "USER_MESSAGE"; + case Packet::VERB_REMOTE_TRACE: return "REMOTE_TRACE"; + } + return "(unknown)"; +} + +static const char *packetErrorString(Packet::ErrorCode e) +{ + switch(e) { + case Packet::ERROR_NONE: return "NONE"; + case Packet::ERROR_INVALID_REQUEST: return "INVALID_REQUEST"; + case Packet::ERROR_BAD_PROTOCOL_VERSION: return "BAD_PROTOCOL_VERSION"; + case Packet::ERROR_OBJ_NOT_FOUND: return "OBJECT_NOT_FOUND"; + case Packet::ERROR_IDENTITY_COLLISION: return "IDENTITY_COLLISION"; + case Packet::ERROR_UNSUPPORTED_OPERATION: return "UNSUPPORTED_OPERATION"; + case Packet::ERROR_NEED_MEMBERSHIP_CERTIFICATE: return "NEED_MEMBERSHIP_CERTIFICATE"; + case Packet::ERROR_NETWORK_ACCESS_DENIED_: return "NETWORK_ACCESS_DENIED"; + case Packet::ERROR_UNWANTED_MULTICAST: return "UNWANTED_MULTICAST"; + } + return "(unknown)"; +} +#endif + +void Trace::resettingPathsInScope(const Address &reporter,const InetAddress &reporterPhysicalAddress,const InetAddress &myPhysicalAddress,const InetAddress::IpScope scope) +{ +} + +void Trace::txTimedOut(const Address &destination) +{ +} + +void Trace::peerConfirmingUnknownPath(Peer &peer,const SharedPtr<Path> &path,const uint64_t packetId,const Packet::Verb verb) +{ +} + +void Trace::peerLearnedNewPath(Peer &peer,const SharedPtr<Path> &oldPath,const SharedPtr<Path> &newPath,const uint64_t packetId) +{ +} + +void Trace::peerRedirected(Peer &peer,const SharedPtr<Path> &oldPath,const SharedPtr<Path> &newPath) +{ +} + +void Trace::outgoingFrameDropped(const SharedPtr<Network> &network,const MAC &sourceMac,const MAC &destMac,const unsigned int etherType,const unsigned int vlanId,const unsigned int frameLen,const char *reason) +{ +} + +void Trace::incomingPacketTrustedPath(const SharedPtr<Path> &path,const uint64_t packetId,const Address &source,const uint64_t trustedPathId,bool approved) +{ +} + +void Trace::incomingPacketMessageAuthenticationFailure(const SharedPtr<Path> &path,const uint64_t packetId,const Address &source) +{ +} + +void Trace::incomingPacketInvalid(const SharedPtr<Path> &path,const uint64_t packetId,const Address &source,const Packet::Verb verb,const char *reason) +{ +} + +void Trace::incomingPacketDroppedHELLO(const SharedPtr<Path> &path,const uint64_t packetId,const Address &source,const char *reason) +{ +} + +void Trace::networkAccessDenied(const SharedPtr<Network> &network,const SharedPtr<Path> &path,const uint64_t packetId,const unsigned int packetLength,const Address &source,const Packet::Verb verb,bool credentialsRequested) +{ +} + +void Trace::networkFrameDropped(const SharedPtr<Network> &network,const SharedPtr<Path> &path,const uint64_t packetId,const unsigned int packetLength,const Address &source,const Packet::Verb verb,const MAC &sourceMac,const MAC &destMac) +{ +} + +void Trace::networkConfigRequestSent(const Network &network,const Address &controller) +{ +} + +void Trace::networkFilter( + const Network &network, + const RuleResultLog &primaryRuleSetLog, + const RuleResultLog *const matchingCapabilityRuleSetLog, + const Capability *const matchingCapability, + const Address &ztSource, + const Address &ztDest, + const MAC &macSource, + const MAC &macDest, + const uint8_t *const frameData, + const unsigned int frameLen, + const unsigned int etherType, + const unsigned int vlanId, + const bool noTee, + const bool inbound, + const int accept) +{ +} + +void Trace::credentialRejected(const CertificateOfMembership &c,const char *reason) +{ +} + +void Trace::credentialRejected(const CertificateOfOwnership &c,const char *reason) +{ +} + +void Trace::credentialRejected(const CertificateOfRepresentation &c,const char *reason) +{ +} + +void Trace::credentialRejected(const Capability &c,const char *reason) +{ +} + +void Trace::credentialRejected(const Tag &c,const char *reason) +{ +} + +void Trace::credentialRejected(const Revocation &c,const char *reason) +{ +} + +void Trace::credentialAccepted(const CertificateOfMembership &c) +{ +} + +void Trace::credentialAccepted(const CertificateOfOwnership &c) +{ +} + +void Trace::credentialAccepted(const CertificateOfRepresentation &c) +{ +} + +void Trace::credentialAccepted(const Capability &c) +{ +} + +void Trace::credentialAccepted(const Tag &c) +{ +} + +void Trace::credentialAccepted(const Revocation &c) +{ +} + +} // namespace ZeroTier diff --git a/node/Trace.hpp b/node/Trace.hpp new file mode 100644 index 00000000..65d1acf1 --- /dev/null +++ b/node/Trace.hpp @@ -0,0 +1,157 @@ +/* + * ZeroTier One - Network Virtualization Everywhere + * Copyright (C) 2011-2017 ZeroTier, Inc. https://www.zerotier.com/ + * + * This program is free software: you can redistribute it and/or modify + * it under the terms of the GNU General Public License as published by + * the Free Software Foundation, either version 3 of the License, or + * (at your option) any later version. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * GNU General Public License for more details. + * + * You should have received a copy of the GNU General Public License + * along with this program. If not, see <http://www.gnu.org/licenses/>. + * + * -- + * + * You can be released from the requirements of the license by purchasing + * a commercial license. Buying such a license is mandatory as soon as you + * develop commercial closed-source software that incorporates or links + * directly against ZeroTier software without disclosing the source code + * of your own application. + */ + +#ifndef ZT_TRACE_HPP +#define ZT_TRACE_HPP + +#include <stdio.h> +#include <stdint.h> +#include <string.h> +#include <stdlib.h> + +#include "../include/ZeroTierOne.h" + +#include "Constants.hpp" +#include "SharedPtr.hpp" +#include "Packet.hpp" +#include "Credential.hpp" +#include "InetAddress.hpp" + +namespace ZeroTier { + +class RuntimeEnvironment; +class Address; +class Identity; +class Peer; +class Path; +class Network; +class NetworkConfig; +class MAC; +class CertificateOfMembership; +class CertificateOfOwnership; +class CertificateOfRepresentation; +class Revocation; +class Tag; +class Capability; + +/** + * Remote tracing and trace logging handler + */ +class Trace +{ +public: + /** + * Filter rule evaluation result log + * + * Each rule in a rule set gets a four-bit log entry. A log entry + * of zero means not evaluated. Otherwise each four-bit log entry + * contains two two-bit values of 01 for 'false' and 10 for 'true'. + * As with four-bit rules an 00 value here means this was not + * evaluated or was not relevant. + */ + class RuleResultLog + { + public: + RuleResultLog() {} + + inline void log(const unsigned int rn,const uint8_t thisRuleMatches,const uint8_t thisSetMatches) + { + _l[rn >> 1] |= ( ((thisRuleMatches + 1) << 2) | (thisSetMatches + 1) ) << ((rn & 1) << 2); + } + inline void logSkipped(const unsigned int rn,const uint8_t thisSetMatches) + { + _l[rn >> 1] |= (thisSetMatches + 1) << ((rn & 1) << 2); + } + + inline void clear() + { + memset(_l,0,sizeof(_l)); + } + + inline const uint8_t *data() const { return _l; } + inline unsigned int sizeBytes() const { return (unsigned int)sizeof(_l); } + + private: + uint8_t _l[ZT_MAX_NETWORK_RULES / 2]; + }; + + Trace(const RuntimeEnvironment *renv) : RR(renv) {} + + void resettingPathsInScope(const Address &reporter,const InetAddress &reporterPhysicalAddress,const InetAddress &myPhysicalAddress,const InetAddress::IpScope scope); + void txTimedOut(const Address &destination); + + void peerConfirmingUnknownPath(Peer &peer,const SharedPtr<Path> &path,const uint64_t packetId,const Packet::Verb verb); + void peerLearnedNewPath(Peer &peer,const SharedPtr<Path> &oldPath,const SharedPtr<Path> &newPath,const uint64_t packetId); + void peerRedirected(Peer &peer,const SharedPtr<Path> &oldPath,const SharedPtr<Path> &newPath); + + void outgoingFrameDropped(const SharedPtr<Network> &network,const MAC &sourceMac,const MAC &destMac,const unsigned int etherType,const unsigned int vlanId,const unsigned int frameLen,const char *reason); + + void incomingPacketTrustedPath(const SharedPtr<Path> &path,const uint64_t packetId,const Address &source,const uint64_t trustedPathId,bool approved); + void incomingPacketMessageAuthenticationFailure(const SharedPtr<Path> &path,const uint64_t packetId,const Address &source); + void incomingPacketInvalid(const SharedPtr<Path> &path,const uint64_t packetId,const Address &source,const Packet::Verb verb,const char *reason); + void incomingPacketDroppedHELLO(const SharedPtr<Path> &path,const uint64_t packetId,const Address &source,const char *reason); + + void networkAccessDenied(const SharedPtr<Network> &network,const SharedPtr<Path> &path,const uint64_t packetId,const unsigned int packetLength,const Address &source,const Packet::Verb verb,bool credentialsRequested); + void networkFrameDropped(const SharedPtr<Network> &network,const SharedPtr<Path> &path,const uint64_t packetId,const unsigned int packetLength,const Address &source,const Packet::Verb verb,const MAC &sourceMac,const MAC &destMac); + + void networkConfigRequestSent(const Network &network,const Address &controller); + void networkFilter( + const Network &network, + const RuleResultLog &primaryRuleSetLog, + const RuleResultLog *const matchingCapabilityRuleSetLog, + const Capability *const matchingCapability, + const Address &ztSource, + const Address &ztDest, + const MAC &macSource, + const MAC &macDest, + const uint8_t *const frameData, + const unsigned int frameLen, + const unsigned int etherType, + const unsigned int vlanId, + const bool noTee, + const bool inbound, + const int accept); + + void credentialRejected(const CertificateOfMembership &c,const char *reason); + void credentialRejected(const CertificateOfOwnership &c,const char *reason); + void credentialRejected(const CertificateOfRepresentation &c,const char *reason); + void credentialRejected(const Capability &c,const char *reason); + void credentialRejected(const Tag &c,const char *reason); + void credentialRejected(const Revocation &c,const char *reason); + void credentialAccepted(const CertificateOfMembership &c); + void credentialAccepted(const CertificateOfOwnership &c); + void credentialAccepted(const CertificateOfRepresentation &c); + void credentialAccepted(const Capability &c); + void credentialAccepted(const Tag &c); + void credentialAccepted(const Revocation &c); + +private: + const RuntimeEnvironment *const RR; +}; + +} // namespace ZeroTier + +#endif |