Add events for packet decode errors, etc., and re-implement TRACE as an event.

include/ZeroTierOne.h

@@ -120,10 +120,10 @@ extern "C" {
 /**
  * Function return code: OK (0) or error results
  *
- * Fatal errors should be interpreted to mean that the node is no longer
- * working correctly. They indicate serious problems such as build problems,
- * an inaccessible data store, system configuration issues, or out of
- * memory.
+ * Use ZT1_ResultCode_isFatal() to check for a fatal error. If a fatal error
+ * occurs, the node should be considered to not be working correctly. These
+ * indicate serious problems like an inaccessible data store or a compile
+ * problem.
  */
 enum ZT1_ResultCode
 {
@@ -145,23 +145,24 @@ enum ZT1_ResultCode
 	ZT1_RESULT_FATAL_ERROR_DATA_STORE_FAILED = 2,
 
 	/**
-	 * Internal error (e.g. unexpected exception, build problem, link problem, etc.)
+	 * Internal error (e.g. unexpected exception indicating bug or build problem)
 	 */
 	ZT1_RESULT_FATAL_ERROR_INTERNAL = 3,
 
 	// Non-fatal errors (>1000)
 
-	/**
-	 * Invalid packet or failed authentication
-	 */
-	ZT1_RESULT_ERROR_PACKET_INVALID = 1000,
-
 	/**
 	 * Network ID not valid
 	 */
-	ZT1_RESULT_ERROR_NETWORK_NOT_FOUND = 1001
+	ZT1_RESULT_ERROR_NETWORK_NOT_FOUND = 1000
 };
 
+/**
+ * @param x Result code
+ * @return True if result code indicates a fatal error
+ */
+#define ZT1_ResultCode_isFatal(x) ((((int)(x)) > 0)&&(((int)(x)) < 1000))
+
 /**
  * Status codes sent to status update callback when things happen
  */
@@ -172,16 +173,22 @@ enum ZT1_Event
 	 *
 	 * This is the first event generated, and is always sent. It may occur
 	 * before Node's constructor returns.
+	 *
+	 * Meta-data: none
 	 */
 	ZT1_EVENT_UP = 0,
 
 	/**
 	 * Node is offline -- network does not seem to be reachable by any available strategy
+	 *
+	 * Meta-data: none
 	 */
 	ZT1_EVENT_OFFLINE = 1,
 
 	/**
 	 * Node is online -- at least one upstream node appears reachable
+	 *
+	 * Meta-data: none
 	 */
 	ZT1_EVENT_ONLINE = 2,
 
@@ -191,6 +198,8 @@ enum ZT1_Event
 	 * This is generated within Node's destructor when it is being shut down.
 	 * It's done for convenience, since cleaning up other state in the event
 	 * handler may appear more idiomatic.
+	 *
+	 * Meta-data: none
 	 */
 	ZT1_EVENT_DOWN = 3,
 
@@ -221,6 +230,8 @@ enum ZT1_Event
 	 * doing so in a mature reliable application. Besides, handling this
 	 * condition is a good way to make sure it never arises. It's like how
 	 * umbrellas prevent rain and smoke detectors prevent fires. They do, right?
+	 *
+	 * Meta-data: none
 	 */
 	ZT1_EVENT_FATAL_ERROR_IDENTITY_COLLISION = 4,
 
@@ -230,8 +241,33 @@ enum ZT1_Event
 	 * Right now this is only triggered if a hub or supernode reports a
 	 * more recent version, and only once. It can be used to trigger a
 	 * software update check.
+	 *
+	 * Meta-data: unsigned int[3], more recent version number
+	 */
+	ZT1_EVENT_SAW_MORE_RECENT_VERSION = 5,
+
+	/**
+	 * A packet failed authentication
+	 *
+	 * Meta-data: struct sockaddr_storage containing origin address of packet
+	 */
+	ZT1_EVENT_AUTHENTICATION_FAILURE = 6,
+
+	/**
+	 * A received packet was not valid
+	 *
+	 * Meta-data: struct sockaddr_storage containing origin address of packet
+	 */
+	ZT1_EVENT_INVALID_PACKET = 7,
+
+	/**
+	 * Trace (debugging) message
+	 *
+	 * These events are only generated if this is a TRACE-enabled build.
+	 *
+	 * Meta-data: C string, TRACE message
 	 */
-	ZT1_EVENT_SAW_MORE_RECENT_VERSION = 5
+	ZT1_EVENT_TRACE = 8
 };
 
 /**
@@ -603,11 +639,15 @@ typedef void ZT1_Node;
 typedef int (*ZT1_VirtualNetworkConfigFunction)(ZT1_Node *,uint64_t,enum ZT1_VirtualNetworkConfigOperation,const ZT1_VirtualNetworkConfig *);
 
 /**
- * Callback for status messages
+ * Callback for events
  *
- * This is called whenever the node's status changes in some significant way.
+ * Events are generated when the node's status changes in a significant way
+ * and on certain non-fatal errors and events of interest. The final void
+ * parameter points to event meta-data. The type of event meta-data (and
+ * whether it is present at all) is event type dependent. See the comments
+ * in the definition of ZT1_Event.
  */
-typedef void (*ZT1_EventCallback)(ZT1_Node *,enum ZT1_Event);
+typedef void (*ZT1_EventCallback)(ZT1_Node *,enum ZT1_Event,const void *);
 
 /**
  * Function to get an object from the data store

node/IncomingPacket.cpp

@@ -213,7 +213,8 @@ bool IncomingPacket::_doHELLO(const RuntimeEnvironment *RR)
 				unsigned char 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
-						LOG("rejected HELLO from %s(%s): address already claimed",id.address().toString().c_str(),_remoteAddress.toString().c_str());
+						RR->node->postEvent(ZT1_EVENT_AUTHENTICATION_FAILURE,(const void *)&_remoteAddress);
+						TRACE("rejected HELLO from %s(%s): address already claimed",id.address().toString().c_str(),_remoteAddress.toString().c_str());
 						Packet outp(id.address(),RR->identity.address(),Packet::VERB_ERROR);
 						outp.append((unsigned char)Packet::VERB_HELLO);
 						outp.append(packetId());
@@ -221,10 +222,12 @@ bool IncomingPacket::_doHELLO(const RuntimeEnvironment *RR)
 						outp.armor(key,true);
 						RR->node->putPacket(_remoteAddress,outp.data(),outp.size(),_linkDesperation);
 					} else {
-						LOG("rejected HELLO from %s(%s): packet failed authentication",id.address().toString().c_str(),_remoteAddress.toString().c_str());
+						RR->node->postEvent(ZT1_EVENT_AUTHENTICATION_FAILURE,(const void *)&_remoteAddress);
+						TRACE("rejected HELLO from %s(%s): packet failed authentication",id.address().toString().c_str(),_remoteAddress.toString().c_str());
 					}
 				} else {
-					LOG("rejected HELLO from %s(%s): key agreement failed",id.address().toString().c_str(),_remoteAddress.toString().c_str());
+					RR->node->postEvent(ZT1_EVENT_AUTHENTICATION_FAILURE,(const void *)&_remoteAddress);
+					TRACE("rejected HELLO from %s(%s): key agreement failed",id.address().toString().c_str(),_remoteAddress.toString().c_str());
 				}
 
 				return true;
@@ -232,7 +235,8 @@ bool IncomingPacket::_doHELLO(const RuntimeEnvironment *RR)
 				// Identity is the same as the one we already have -- check packet integrity
 
 				if (!dearmor(peer->key())) {
-					LOG("rejected HELLO from %s(%s): packet failed authentication",id.address().toString().c_str(),_remoteAddress.toString().c_str());
+					RR->node->postEvent(ZT1_EVENT_AUTHENTICATION_FAILURE,(const void *)&_remoteAddress);
+					TRACE("rejected HELLO from %s(%s): packet failed authentication",id.address().toString().c_str(),_remoteAddress.toString().c_str());
 					return true;
 				}
 
@@ -242,13 +246,15 @@ bool IncomingPacket::_doHELLO(const RuntimeEnvironment *RR)
 			// We don't already have an identity with this address -- validate and learn it
 
 			if (!id.locallyValidate()) {
+				RR->node->postEvent(ZT1_EVENT_AUTHENTICATION_FAILURE,(const void *)&_remoteAddress);
 				TRACE("dropped HELLO from %s(%s): identity invalid",id.address().toString().c_str(),_remoteAddress.toString().c_str());
 				return true;
 			}
 
 			SharedPtr<Peer> newPeer(new Peer(RR->identity,id));
 			if (!dearmor(newPeer->key())) {
-				LOG("rejected HELLO from %s(%s): packet failed authentication",id.address().toString().c_str(),_remoteAddress.toString().c_str());
+				RR->node->postEvent(ZT1_EVENT_AUTHENTICATION_FAILURE,(const void *)&_remoteAddress);
+				TRACE("rejected HELLO from %s(%s): packet failed authentication",id.address().toString().c_str(),_remoteAddress.toString().c_str());
 				return true;
 			}
 
@@ -672,7 +678,7 @@ bool IncomingPacket::_doNETWORK_CONFIG_REQUEST(const RuntimeEnvironment *RR,cons
 				case NetworkConfigMaster::NETCONF_QUERY_OK: {
 					const std::string netconfStr(netconf.toString());
 					if (netconfStr.length() > 0xffff) { // sanity check since field ix 16-bit
-						LOG("NETWORK_CONFIG_REQUEST failed: internal error: netconf size %u is too large",(unsigned int)netconfStr.length());
+						TRACE("NETWORK_CONFIG_REQUEST failed: internal error: netconf size %u is too large",(unsigned int)netconfStr.length());
 					} else {
 						Packet outp(peer->address(),RR->identity.address(),Packet::VERB_OK);
 						outp.append((unsigned char)Packet::VERB_NETWORK_CONFIG_REQUEST);
@@ -682,7 +688,7 @@ bool IncomingPacket::_doNETWORK_CONFIG_REQUEST(const RuntimeEnvironment *RR,cons
 						outp.append(netconfStr.data(),netconfStr.length());
 						outp.compress();
 						if (outp.size() > ZT_PROTO_MAX_PACKET_LENGTH) {
-							LOG("NETWORK_CONFIG_REQUEST failed: internal error: netconf size %u is too large",(unsigned int)netconfStr.length());
+							TRACE("NETWORK_CONFIG_REQUEST failed: internal error: netconf size %u is too large",(unsigned int)netconfStr.length());
 						} else {
 							RR->node->putPacket(_remoteAddress,outp.data(),outp.size(),_linkDesperation);
 						}
@@ -709,7 +715,7 @@ bool IncomingPacket::_doNETWORK_CONFIG_REQUEST(const RuntimeEnvironment *RR,cons
 					RR->node->putPacket(_remoteAddress,outp.data(),outp.size(),_linkDesperation);
 				} break;
 				case NetworkConfigMaster::NETCONF_QUERY_INTERNAL_SERVER_ERROR:
-					LOG("NETWORK_CONFIG_REQUEST failed: internal error: %s",netconf.get("error","(unknown)").c_str());
+					TRACE("NETWORK_CONFIG_REQUEST failed: internal error: %s",netconf.get("error","(unknown)").c_str());
 					break;
 				default:
 					TRACE("NETWORK_CONFIG_REQUEST failed: invalid return value from NetworkConfigMaster::doNetworkConfigRequest()");

node/Network.cpp

@@ -199,12 +199,12 @@ bool Network::applyConfiguration(const SharedPtr<NetworkConfig> &conf)
 
 			return true;
 		} else {
-			LOG("ignored invalid configuration for network %.16llx (configuration contains mismatched network ID or issued-to address)",(unsigned long long)_id);
+			TRACE("ignored invalid configuration for network %.16llx (configuration contains mismatched network ID or issued-to address)",(unsigned long long)_id);
 		}
 	} catch (std::exception &exc) {
-		LOG("ignored invalid configuration for network %.16llx (%s)",(unsigned long long)_id,exc.what());
+		TRACE("ignored invalid configuration for network %.16llx (%s)",(unsigned long long)_id,exc.what());
 	} catch ( ... ) {
-		LOG("ignored invalid configuration for network %.16llx (unknown exception)",(unsigned long long)_id);
+		TRACE("ignored invalid configuration for network %.16llx (unknown exception)",(unsigned long long)_id);
 	}
 	return false;
 }
@@ -227,7 +227,7 @@ int Network::setConfiguration(const Dictionary &conf,bool saveToDisk)
 			return 2; // OK and configuration has changed
 		}
 	} catch ( ... ) {
-		LOG("ignored invalid configuration for network %.16llx (dictionary decode failed)",(unsigned long long)_id);
+		TRACE("ignored invalid configuration for network %.16llx (dictionary decode failed)",(unsigned long long)_id);
 	}
 	return 0;
 }
@@ -288,7 +288,7 @@ void Network::addMembershipCertificate(const CertificateOfMembership &cert,bool
 	// Check signature, log and return if cert is invalid
 	if (!forceAccept) {
 		if (cert.signedBy() != controller()) {
-			LOG("rejected network membership certificate for %.16llx signed by %s: signer not a controller of this network",(unsigned long long)_id,cert.signedBy().toString().c_str());
+			TRACE("rejected network membership certificate for %.16llx signed by %s: signer not a controller of this network",(unsigned long long)_id,cert.signedBy().toString().c_str());
 			return;
 		}
 
@@ -302,7 +302,7 @@ void Network::addMembershipCertificate(const CertificateOfMembership &cert,bool
 		}
 
 		if (!cert.verify(signer->identity())) {
-			LOG("rejected network membership certificate for %.16llx signed by %s: signature check failed",(unsigned long long)_id,cert.signedBy().toString().c_str());
+			TRACE("rejected network membership certificate for %.16llx signed by %s: signature check failed",(unsigned long long)_id,cert.signedBy().toString().c_str());
 			return;
 		}
 	}

node/Network.hpp

@@ -333,6 +333,13 @@ public:
 	 */
 	void destroy();
 
+	inline bool operator==(const Network &n) const throw() { return (_id == n._id); }
+	inline bool operator!=(const Network &n) const throw() { return (_id != n._id); }
+	inline bool operator<(const Network &n) const throw() { return (_id < n._id); }
+	inline bool operator>(const Network &n) const throw() { return (_id > n._id); }
+	inline bool operator<=(const Network &n) const throw() { return (_id <= n._id); }
+	inline bool operator>=(const Network &n) const throw() { return (_id >= n._id); }
+
 private:
 	ZT1_VirtualNetworkStatus _status() const;
 	void _externalConfig(ZT1_VirtualNetworkConfig *ec) const; // assumes _lock is locked

node/Node.cpp

@@ -175,14 +175,10 @@ ZT1_ResultCode Node::processVirtualNetworkFrame(
 			return rc;
 	} else _now = now;
 
-	try {
-		SharedPtr<Network> nw(network(nwid));
-		if (nw)
-			RR->sw->onLocalEthernet(nw,MAC(sourceMac),MAC(destMac),etherType,vlanId,frameData,frameLength);
-		else return ZT1_RESULT_ERROR_NETWORK_NOT_FOUND;
-	} catch ( ... ) {
-		return ZT1_RESULT_FATAL_ERROR_INTERNAL;
-	}
+	SharedPtr<Network> nw(network(nwid));
+	if (nw)
+		RR->sw->onLocalEthernet(nw,MAC(sourceMac),MAC(destMac),etherType,vlanId,frameData,frameLength);
+	else return ZT1_RESULT_ERROR_NETWORK_NOT_FOUND;
 
 	return ZT1_RESULT_OK;
 }
@@ -364,10 +360,37 @@ void Node::postNewerVersionIfNewer(unsigned int major,unsigned int minor,unsigne
 		_newestVersionSeen[0] = major;
 		_newestVersionSeen[1] = minor;
 		_newestVersionSeen[2] = rev;
-		this->postEvent(ZT1_EVENT_SAW_MORE_RECENT_VERSION);
+		this->postEvent(ZT1_EVENT_SAW_MORE_RECENT_VERSION,(const void *)_newestVersionSeen);
 	}
 }
 
+#ifdef ZT_TRACE
+void Node::postTrace(const char *module,unsigned int line,const char *fmt,...)
+{
+	static Mutex traceLock;
+
+	va_list ap;
+	char tmp1[1024],tmp2[1024],tmp3[256];
+
+	Mutex::Lock _l(traceLock);
+
+#ifdef __WINDOWS__
+	ctime_s(tmp3,sizeof(tmp3),&now);
+	const char *nowstr = tmp3;
+#else
+	const char *nowstr = ctime_r(&now,tmp3);
+#endif
+
+	va_start(ap,fmt);
+	vsnprintf(tmp2,sizeof(tmp2),fmt,ap);
+	va_end(ap);
+	tmp2[sizeof(tmp2)-1] = (char)0;
+
+	Utils::snprintf(tmp1,sizeof(tmp1),"[%s] %s:%u %s",nowstr,module,line,tmp2);
+	postEvent(ZT1_EVENT_TRACE,tmp1);
+}
+#endif // ZT_TRACE
+
 } // namespace ZeroTier
 
 /****************************************************************************/
@@ -421,7 +444,8 @@ enum ZT1_ResultCode ZT1_Node_processWirePacket(
 	} catch (std::bad_alloc &exc) {
 		return ZT1_RESULT_FATAL_ERROR_OUT_OF_MEMORY;
 	} catch ( ... ) {
-		return ZT1_RESULT_ERROR_PACKET_INVALID;
+		reinterpret_cast<ZeroTier::Node *>(node)->postEvent(ZT1_EVENT_INVALID_PACKET,(const void *)remoteAddress);
+		return ZT1_RESULT_OK;
 	}
 }
 

node/Node.hpp

@@ -43,6 +43,13 @@
 #include "MAC.hpp"
 #include "Network.hpp"
 
+#undef TRACE
+#ifdef ZT_TRACE
+#define TRACE(f,...) RR->node->postTrace(__FILE__,__LINE__,f,##__VA_ARGS__)
+#else
+#define TRACE(f,...) {}
+#endif
+
 namespace ZeroTier {
 
 class RuntimeEnvironment;
@@ -164,6 +171,9 @@ public:
 		return nw;
 	}
 
+	/**
+	 * @return Overall system level of desperation based on how long it's been since an upstream node (supernode) has talked to us
+	 */
 	inline unsigned int coreDesperation() const throw() { return _coreDesperation; }
 
 	inline bool dataStorePut(const char *name,const void *data,unsigned int len,bool secure) { return (_dataStorePutFunction(reinterpret_cast<ZT1_Node *>(this),name,data,len,(int)secure) == 0); }
@@ -171,12 +181,32 @@ public:
 	inline void dataStoreDelete(const char *name) { _dataStorePutFunction(reinterpret_cast<ZT1_Node *>(this),name,(const void *)0,0,0); }
 	std::string dataStoreGet(const char *name);
 
-	inline void postEvent(ZT1_Event ev) { _eventCallback(reinterpret_cast<ZT1_Node *>(this),ev); }
+	/**
+	 * Post an event to the external user
+	 *
+	 * @param ev Event type
+	 * @param md Meta-data (default: NULL/none)
+	 */
+	inline void postEvent(ZT1_Event ev,const void *md = (const void *)0) { _eventCallback(reinterpret_cast<ZT1_Node *>(this),ev,md); }
 
+	/**
+	 * Update virtual network port configuration
+	 *
+	 * @param nwid Network ID
+	 * @param op Configuration operation
+	 * @param nc Network configuration
+	 */
 	inline int configureVirtualNetworkPort(uint64_t nwid,ZT1_VirtualNetworkConfigOperation op,const ZT1_VirtualNetworkConfig *nc) { return _virtualNetworkConfigFunction(reinterpret_cast<ZT1_Node *>(this),nwid,op,nc); }
 
+	/**
+	 * If this version is newer than the newest we've seen, post a new version seen event
+	 */
 	void postNewerVersionIfNewer(unsigned int major,unsigned int minor,unsigned int rev);
 
+#ifdef ZT_TRACE
+	void postTrace(const char *module,unsigned int line,const char *fmt,...);
+#endif
+
 private:
 	RuntimeEnvironment *RR;
 

node/Switch.cpp

@@ -106,7 +106,7 @@ void Switch::onLocalEthernet(const SharedPtr<Network> &network,const MAC &from,c
 	bool fromBridged = false;
 	if (from != network->mac()) {
 		if (!network->permitsBridging(RR->identity.address())) {
-			LOG("%.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));
+			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));
 			return;
 		}
 		fromBridged = true;

node/Topology.cpp

@@ -86,7 +86,7 @@ void Topology::setSupernodes(const Dictionary &sn)
 				if (udp.length() > 0)
 					a.push_back(InetAddress(udp));
 			} catch ( ... ) {
-				LOG("supernode list contained invalid entry for: %s",d->first.c_str());
+				TRACE("supernode list contained invalid entry for: %s",d->first.c_str());
 			}
 		}
 	}