Remove extra verbose logging from controller

nonfree/controller/BigTableStatusWriter.cpp

@@ -87,7 +87,6 @@ void BigTableStatusWriter::writePending()
 	if (toWrite.empty()) {
 		return;
 	}
-	fprintf(stderr, "Writing %zu pending status entries to BigTable\n", toWrite.size());
 
 	cbt::BulkMutation bulk;
 	for (const auto& entry : toWrite) {

nonfree/controller/CentralDB.cpp

@@ -319,13 +319,11 @@ bool CentralDB::save(nlohmann::json& record, bool notifyListeners)
 			auto span = tracer->StartSpan("CentralDB::save::network");
 			auto scope = tracer->WithActiveSpan(span);
 
-			fprintf(stderr, "CentralDB network save %s\n", record["id"].get<std::string>().c_str());
 			const uint64_t nwid = OSUtils::jsonIntHex(record["id"], 0ULL);
 			if (nwid) {
 				nlohmann::json old;
 				get(nwid, old);
 				if ((! old.is_object()) || (! _compareRecords(old, record))) {
-					fprintf(stderr, "posting network change to commit queue\n");
 					record["revision"] = OSUtils::jsonInt(record["revision"], 0ULL) + 1ULL;
 					_queueItem qi;
 					qi.jsonData = record;
@@ -348,12 +346,10 @@ bool CentralDB::save(nlohmann::json& record, bool notifyListeners)
 			std::string memberId = record["id"];
 			const uint64_t nwid = OSUtils::jsonIntHex(record["nwid"], 0ULL);
 			const uint64_t id = OSUtils::jsonIntHex(record["id"], 0ULL);
-			fprintf(stderr, "member save %s-%s\n", networkId.c_str(), memberId.c_str());
 			if ((id) && (nwid)) {
 				nlohmann::json network, old;
 				get(nwid, network, id, old);
 				if ((! old.is_object()) || (! _compareRecords(old, record))) {
-					fprintf(stderr, "posting member change to commit queue\n");
 					record["revision"] = OSUtils::jsonInt(record["revision"], 0ULL) + 1ULL;
 
 					_queueItem qi;
@@ -395,7 +391,6 @@ void CentralDB::eraseNetwork(const uint64_t networkId)
 	char networkIdStr[17];
 	span->SetAttribute("network_id", Utils::hex(networkId, networkIdStr));
 
-	fprintf(stderr, "CentralDB::eraseNetwork\n");
 	char tmp2[24];
 	waitForReady();
 	Utils::hex(networkId, tmp2);
@@ -425,7 +420,6 @@ void CentralDB::eraseMember(const uint64_t networkId, const uint64_t memberId)
 	span->SetAttribute("network_id", Utils::hex(networkId, networkIdStr));
 	span->SetAttribute("member_id", Utils::hex10(memberId, memberIdStr));
 
-	fprintf(stderr, "CentralDB::eraseMember\n");
 	char tmp2[24];
 	waitForReady();
 
@@ -1149,11 +1143,6 @@ void CentralDB::commitThread()
 		auto provider = opentelemetry::trace::Provider::GetTracerProvider();
 		auto tracer = provider->GetTracer("CentralDB");
 
-		fprintf(stderr, "checking qitem trace context\n");
-		for (auto const& kv : qitem.traceContext) {
-			fprintf(stderr, "traceContext: %s: %s\n", kv.first.c_str(), kv.second.c_str());
-		}
-
 		auto propagator = opentelemetry::context::propagation::GlobalTextMapPropagator::GetGlobalPropagator();
 		OtelCarrier<std::map<std::string, std::string> > carrier(qitem.traceContext);
 		auto current_ctx = opentelemetry::context::RuntimeContext::GetCurrent();
@@ -1202,7 +1191,6 @@ void CentralDB::commitThread()
 
 						memberId = config["id"];
 						networkId = config["nwid"];
-						fprintf(stderr, "commit member %s-%s\n", networkId.c_str(), memberId.c_str());
 
 						std::string target = "NULL";
 						if (! config["remoteTraceTarget"].is_null()) {
@@ -1243,18 +1231,12 @@ void CentralDB::commitThread()
 							change_source = "controller";
 						}
 						if (! isNewMember && change_source != "controller" && frontend != change_source) {
-							fprintf(
-								stderr, "skipping member %s-%s update.  change source: %s, frontend: %s\n",
-								networkId.c_str(), memberId.c_str(), change_source.c_str(), frontend.c_str());
 							// if it is not a new member and the change source is not the controller and doesn't match
 							// the frontend, don't apply the change.
 							continue;
 						}
 
 						std::vector<std::string> ipAssignments;
-						fprintf(
-							stderr, "Saving IP Assignments: \n\tipAssignments: %s\n",
-							OSUtils::jsonDump(config["ipAssignments"], -1).c_str());
 						if (config["ipAssignments"].is_array()) {
 							for (auto& ip : config["ipAssignments"]) {
 								if (ip.is_string()) {
@@ -1263,8 +1245,6 @@ void CentralDB::commitThread()
 							}
 						}
 
-						fprintf(stderr, "member json: %s\n", config.dump().c_str());
-
 						int64_t vMajor = OSUtils::jsonUInt(config["vMajor"], 0);
 						int64_t vMinor = OSUtils::jsonUInt(config["vMinor"], 0);
 						int64_t vRev = OSUtils::jsonUInt(config["vRev"], 0);
@@ -1399,7 +1379,6 @@ void CentralDB::commitThread()
 						pqxx::work w(*c->c);
 
 						std::string id = config["id"];
-						fprintf(stderr, "commit network %s\n", id.c_str());
 
 						pqxx::row nwrow =
 							w.exec("SELECT COUNT(id) frontend FROM networks_ctl WHERE id = $1", pqxx::params { id })
@@ -1423,10 +1402,6 @@ void CentralDB::commitThread()
 						if (! isNewNetwork && change_source != "controller" && frontend != change_source) {
 							// if it is not a new network and the change source is not the controller and doesn't match
 							// the frontend, don't apply the change.
-							fprintf(
-								stderr,
-								"Skipping network update %s. isNewNetwork: %s, change_source: %s, frontend: %s\n",
-								id.c_str(), isNewNetwork ? "true" : "false", change_source.c_str(), frontend.c_str());
 							continue;
 						}
 
@@ -1499,7 +1474,6 @@ void CentralDB::commitThread()
 					try {
 						pqxx::work w(*c->c);
 						std::string networkId = config["id"];
-						fprintf(stderr, "Deleting network %s\n", networkId.c_str());
 						w.exec("DELETE FROM network_memberships_ctl WHERE network_id = $1", pqxx::params { networkId });
 						w.exec("DELETE FROM networks_ctl WHERE id = $1", pqxx::params { networkId });
 
@@ -1546,8 +1520,6 @@ void CentralDB::commitThread()
 						std::string memberId = config["id"];
 						std::string networkId = config["nwid"];
 
-						fprintf(stderr, "Deleting member %s-%s\n", networkId.c_str(), memberId.c_str());
-
 						pqxx::result res =
 							w.exec(
 								 "DELETE FROM network_memberships_ctl WHERE device_id = $1 AND network_id = $2",

nonfree/controller/EmbeddedNetworkController.cpp

@@ -1655,7 +1655,6 @@ void EmbeddedNetworkController::onNetworkMemberDeauthorize(const void* db, uint6
 	auto span = tracer->StartSpan("embedded_controller::onNetworkMemberDeauthorize");
 	auto scope = tracer->WithActiveSpan(span);
 
-	fprintf(stderr, "Member Deauthorized: nwid=%.16llx, nodeid=%.10llx\n", networkId, memberId);
 	const int64_t now = OSUtils::now();
 	Revocation rev(
 		(uint32_t)_node->prng(), networkId, 0, now, ZT_REVOCATION_FLAG_FAST_PROPAGATE, Address(memberId),
@@ -1666,10 +1665,7 @@ void EmbeddedNetworkController::onNetworkMemberDeauthorize(const void* db, uint6
 		for (auto i = _memberStatus.begin(); i != _memberStatus.end(); ++i) {
 			if ((i->first.networkId == networkId) && (i->second.online(now))) {
 				_node->ncSendRevocation(Address(i->first.nodeId), rev);
-				fprintf(stderr, "  Sent revocation to %.10llx\n", i->first.nodeId);
-			}
-			else {
-				fprintf(stderr, "  Not sending revocation to %.10llx\n", i->first.nodeId);
+				// fprintf(stderr, "  Sent revocation to %.10llx\n", i->first.nodeId);
 			}
 		}
 	}
@@ -2307,20 +2303,10 @@ void EmbeddedNetworkController::_request(
 		}
 	}
 
-	fprintf(stderr, "haveManagedIpv4AutoAssignment=%s\n", haveManagedIpv4AutoAssignment ? "true" : "false");
-	fprintf(stderr, "ipAssignmentPools.is_array()=%s\n", ipAssignmentPools.is_array() ? "true" : "false");
-	fprintf(stderr, "v4AssignMode.is_object()=%s\n", v4AssignMode.is_object() ? "true" : "false");
-	fprintf(
-		stderr, "v4AssignMode[\"zt\"]=%s\n",
-		(v4AssignMode.is_object() && OSUtils::jsonBool(v4AssignMode["zt"], false)) ? "true" : "false");
-	fprintf(stderr, "noAutoAssignIps=%s\n", noAutoAssignIps ? "true" : "false");
-
 	if ((ipAssignmentPools.is_array()) && ((v4AssignMode.is_object()) && (OSUtils::jsonBool(v4AssignMode["zt"], false)))
 		&& (! haveManagedIpv4AutoAssignment) && (! noAutoAssignIps)) {
-		fprintf(stderr, "Trying to do managed IPv4 auto-assignment\n");
 		for (unsigned long p = 0; ((p < ipAssignmentPools.size()) && (! haveManagedIpv4AutoAssignment)); ++p) {
 			json& pool = ipAssignmentPools[p];
-			fprintf(stderr, "  considering pool %lu: %s\n", p, OSUtils::jsonDump(pool, 2).c_str());
 			if (pool.is_object()) {
 				InetAddress ipRangeStartIA(OSUtils::jsonString(pool["ipRangeStart"], "").c_str());
 				InetAddress ipRangeEndIA(OSUtils::jsonString(pool["ipRangeEnd"], "").c_str());
@@ -2371,7 +2357,6 @@ void EmbeddedNetworkController::_request(
 							char tmpip[64];
 							const std::string ipStr(ip4.toIpString(tmpip));
 							if (std::find(ipAssignments.begin(), ipAssignments.end(), ipStr) == ipAssignments.end()) {
-								fprintf(stderr, "  assigning %s\n", ipStr.c_str());
 								ipAssignments.push_back(ipStr);
 								member["ipAssignments"] = ipAssignments;
 								if (nc->staticIpCount < ZT_MAX_ZT_ASSIGNED_ADDRESSES) {

nonfree/controller/PostgreSQL.cpp

@@ -57,7 +57,6 @@ bool PostgresMemberListener::onNotification(const std::string& payload)
 	auto scope = tracer->WithActiveSpan(span);
 	span->SetAttribute("payload", payload);
 
-	fprintf(stderr, "Member Notification received: %s\n", payload.c_str());
 	Metrics::pgsql_mem_notification++;
 	nlohmann::json tmp(nlohmann::json::parse(payload));
 	nlohmann::json& ov = tmp["old_val"];
@@ -70,13 +69,11 @@ bool PostgresMemberListener::onNotification(const std::string& payload)
 
 	if (oldConfig.is_object() && newConfig.is_object()) {
 		_db->save(newConfig, true);
-		fprintf(stderr, "payload sent\n");
 	}
 	else if (newConfig.is_object() && ! oldConfig.is_object()) {
 		// new member
 		Metrics::member_count++;
 		_db->save(newConfig, true);
-		fprintf(stderr, "new member payload sent\n");
 	}
 	else if (! newConfig.is_object() && oldConfig.is_object()) {
 		// member delete
@@ -84,7 +81,6 @@ bool PostgresMemberListener::onNotification(const std::string& payload)
 		uint64_t memberId = OSUtils::jsonIntHex(oldConfig["id"], 0ULL);
 		if (memberId && networkId) {
 			_db->eraseMember(networkId, memberId);
-			fprintf(stderr, "member delete payload sent\n");
 		}
 	}
 	return true;
@@ -135,7 +131,6 @@ bool PostgresNetworkListener::onNotification(const std::string& payload)
 	auto scope = tracer->WithActiveSpan(span);
 	span->SetAttribute("payload", payload);
 
-	fprintf(stderr, "Network Notification received: %s\n", payload.c_str());
 	Metrics::pgsql_net_notification++;
 	nlohmann::json tmp(nlohmann::json::parse(payload));
 
@@ -153,7 +148,6 @@ bool PostgresNetworkListener::onNotification(const std::string& payload)
 		span->SetAttribute("action", "network_change");
 		span->SetAttribute("network_id", nwid);
 		_db->save(newConfig, true);
-		fprintf(stderr, "payload sent\n");
 	}
 	else if (newConfig.is_object() && ! oldConfig.is_object()) {
 		std::string nwid = newConfig["id"];
@@ -161,7 +155,6 @@ bool PostgresNetworkListener::onNotification(const std::string& payload)
 		span->SetAttribute("action", "new_network");
 		// new network
 		_db->save(newConfig, true);
-		fprintf(stderr, "new network payload sent\n");
 	}
 	else if (! newConfig.is_object() && oldConfig.is_object()) {
 		// network delete
@@ -172,7 +165,6 @@ bool PostgresNetworkListener::onNotification(const std::string& payload)
 		span->SetAttribute("network_id_int", networkId);
 		if (networkId) {
 			_db->eraseNetwork(networkId);
-			fprintf(stderr, "network delete payload sent\n");
 		}
 	}
 	return true;

nonfree/controller/PubSubListener.cpp

@@ -80,7 +80,6 @@ void PubSubListener::subscribe()
 {
 	while (_run) {
 		try {
-			fprintf(stderr, "Starting new subscription session\n");
 			auto session = _subscriber->Subscribe([this](pubsub::Message const& m, pubsub::AckHandler h) {
 				auto provider = opentelemetry::trace::Provider::GetTracerProvider();
 				auto tracer = provider->GetTracer("PubSubListener");
@@ -89,7 +88,6 @@ void PubSubListener::subscribe()
 				auto attrs = m.attributes();
 				std::map<std::string, std::string> attrs_map;
 				for (auto const& kv : m.attributes()) {
-					fprintf(stderr, "Message attribute: %s=%s\n", kv.first.c_str(), kv.second.c_str());
 					attrs_map.emplace(kv.first, kv.second);
 				}
 
@@ -106,7 +104,6 @@ void PubSubListener::subscribe()
 					span->SetAttribute("message_id", m.message_id());
 					span->SetAttribute("ordering_key", m.ordering_key());
 
-					fprintf(stderr, "Received message %s\n", m.message_id().c_str());
 					if (onNotification(m.data())) {
 						std::move(h).ack();
 						span->SetStatus(opentelemetry::trace::StatusCode::kOk);
@@ -160,8 +157,6 @@ bool PubSubNetworkListener::onNotification(const std::string& payload)
 		span->SetStatus(opentelemetry::trace::StatusCode::kError, "Failed to parse protobuf");
 		return false;
 	}
-	fprintf(stderr, "PubSubNetworkListener: parsed protobuf message. %s\n", nc.DebugString().c_str());
-	fprintf(stderr, "Network notification received\n");
 
 	try {
 		nlohmann::json oldConfig, newConfig;
@@ -228,7 +223,6 @@ bool PubSubNetworkListener::onNotification(const std::string& payload)
 		span->SetStatus(opentelemetry::trace::StatusCode::kError, "Unknown exception");
 		return false;
 	}
-	fprintf(stderr, "PubSubNetworkListener onNotification complete\n");
 	return true;
 }
 
@@ -256,8 +250,6 @@ bool PubSubMemberListener::onNotification(const std::string& payload)
 		span->SetStatus(opentelemetry::trace::StatusCode::kError, "Failed to parse protobuf");
 		return false;
 	}
-	fprintf(stderr, "PubSubMemberListener: parsed protobuf message. %s\n", mc.DebugString().c_str());
-	fprintf(stderr, "Member notification received");
 
 	try {
 		nlohmann::json tmp;

nonfree/controller/PubSubWriter.cpp

@@ -64,7 +64,6 @@ bool PubSubWriter::publishMessage(
 	auto span = tracer->StartSpan("PubSubWriter::publishMessage");
 	auto scope = tracer->WithActiveSpan(span);
 
-	fprintf(stderr, "Publishing message to %s\n", _topic.c_str());
 	std::vector<std::pair<std::string, std::string> > attributes;
 	attributes.emplace_back("controller_id", _controller_id);
 
@@ -75,7 +74,6 @@ bool PubSubWriter::publishMessage(
 	propagator->Inject(carrier, current_ctx);
 
 	for (const auto& kv : attrs_map) {
-		fprintf(stderr, "Attributes injected: %s=%s\n", kv.first.c_str(), kv.second.c_str());
 		attributes.emplace_back(kv.first, kv.second);
 	}
 
@@ -94,7 +92,6 @@ bool PubSubWriter::publishMessage(
 		return false;
 	}
 
-	fprintf(stderr, "Published message to %s\n", _topic.c_str());
 	return true;
 }
 
@@ -103,7 +100,6 @@ bool PubSubWriter::publishNetworkChange(
 	const nlohmann::json& newNetwork,
 	const std::string& frontend)
 {
-	fprintf(stderr, "Publishing network change\n");
 	pbmessages::NetworkChange* nc = networkChangeFromJson(_controller_id, oldNetwork, newNetwork);
 
 	std::string networkID;
@@ -129,7 +125,6 @@ bool PubSubWriter::publishMemberChange(
 	const nlohmann::json& newMember,
 	const std::string& frontend)
 {
-	fprintf(stderr, "Publishing member change\n");
 	pbmessages::MemberChange* mc = memberChangeFromJson(_controller_id, oldMember, newMember);
 	std::string memberID;
 	if (mc->has_new_()) {
@@ -314,8 +309,6 @@ pbmessages::MemberChange_Member* memberFromJson(const nlohmann::json& j)
 		return nullptr;
 	}
 
-	fprintf(stderr, "memberFromJSON: %s\n", j.dump().c_str());
-
 	pbmessages::MemberChange_Member* m = new pbmessages::MemberChange_Member();
 	try {
 		m->set_network_id(OSUtils::jsonString(j["nwid"], ""));
@@ -373,15 +366,12 @@ pbmessages::MemberChange_Member* memberFromJson(const nlohmann::json& j)
 		delete m;
 		return nullptr;
 	}
-	fprintf(stderr, "memberFromJSON complete\n");
 	return m;
 }
 
 pbmessages::MemberChange*
 memberChangeFromJson(std::string controllerID, const nlohmann::json& oldMember, const nlohmann::json& newMember)
 {
-	fprintf(stderr, "memberrChangeFromJson: old: %s\n", oldMember.dump().c_str());
-	fprintf(stderr, "memberrChangeFromJson: new: %s\n", newMember.dump().c_str());
 	pbmessages::MemberChange* mc = new pbmessages::MemberChange();
 	pbmessages::MemberChange_Member* om = memberFromJson(oldMember);
 	if (om != nullptr) {