Merge pull request #832 from pi-hole/new/cname_inspection_logging

Add logging for CNAME inspection
2024-10-26 16:52:18 +02:00 · 2020-07-23 06:19:17 +02:00
parent a70cd5279f 4a4681318c
commit 5f4582e436
6 changed files with 156 additions and 65 deletions
@@ -361,6 +361,24 @@ void db_init(void)
 		dbversion = db_get_FTL_property(DB_VERSION);
 	}

+	// Update to version 7 if lower
+	if(dbversion < 7)
+	{
+		// Update to version 7: Create message table
+		logg("Updating long-term database to version 7");
+		if(dbquery("ALTER TABLE queries ADD COLUMN additional_info TEXT;") != SQLITE_OK ||
+		   !db_set_FTL_property(DB_VERSION, 7))
+		{
+			logg("Column additional_info not initialized, database not available");
+			dbclose();
+
+			database = false;
+			return;
+		}
+		// Get updated version
+		dbversion = db_get_FTL_property(DB_VERSION);
+	}
+
 	// Close database to prevent having it opened all time
 	// We already closed the database when we returned earlier
 	dbclose();
@@ -81,7 +81,7 @@ void DB_save_queries(void)
 		return;
 	}

-	rc = sqlite3_prepare_v2(FTL_db, "INSERT INTO queries VALUES (NULL,?,?,?,?,?,?)", -1, &stmt, NULL);
+	rc = sqlite3_prepare_v2(FTL_db, "INSERT INTO queries VALUES (NULL,?,?,?,?,?,?,?)", -1, &stmt, NULL);
 	if( rc != SQLITE_OK )
 	{
 		const char *text, *spaces;
@@ -165,6 +165,31 @@ void DB_save_queries(void)
 			sqlite3_bind_null(stmt, 6);
 		}

+		// ADDITIONAL_INFO
+		if(query->status == QUERY_GRAVITY_CNAME ||
+		   query->status == QUERY_REGEX_CNAME ||
+		   query->status == QUERY_BLACKLIST_CNAME)
+		{
+			// Restore domain blocked during deep CNAME inspection if applicable
+			const char* cname = getCNAMEDomainString(query);
+			sqlite3_bind_text(stmt, 7, cname, -1, SQLITE_STATIC);
+		}
+		else if(query->status == QUERY_REGEX)
+		{
+			// Restore regex ID if applicable
+			const int cacheID = findCacheID(query->domainID, query->clientID);
+			DNSCacheData *cache = getDNSCache(cacheID, true);
+			if(cache != NULL)
+				sqlite3_bind_int(stmt, 7, cache->black_regex_idx);
+			else
+				sqlite3_bind_null(stmt, 7);
+		}
+		else
+		{
+			// Nothing to add here
+			sqlite3_bind_null(stmt, 7);
+		}
+
 		// Step and check if successful
 		rc = sqlite3_step(stmt);
 		sqlite3_clear_bindings(stmt);
@@ -444,6 +469,33 @@ void DB_read_queries(void)
 		// Increase DNS queries counter
 		counters->queries++;

+		// Get additional information from the additional_info column if applicable
+		if(status == QUERY_GRAVITY_CNAME ||
+		   status == QUERY_REGEX_CNAME ||
+		   status == QUERY_BLACKLIST_CNAME)
+		{
+			// QUERY_*_CNAME: Getdomain causing the blocking
+			const char *CNAMEdomain = (const char *)sqlite3_column_text(stmt, 7);
+			if(CNAMEdomain != NULL && strlen(CNAMEdomain) > 0)
+			{
+				// Add domain to FTL's memory but do not count it. Seeing a
+				// domain in the middle of a CNAME trajectory does not mean
+				// it was queried intentionally.
+				const int CNAMEdomainID = findDomainID(CNAMEdomain, false);
+				query->CNAME_domainID = CNAMEdomainID;
+			}
+		}
+		else if(status == QUERY_REGEX)
+		{
+			// QUERY_REGEX: Set ID regex which was the reson for blocking
+			const int cacheID = findCacheID(query->domainID, query->clientID);
+			const DNSCacheData *cache = getDNSCache(cacheID, true);
+			if(cache != NULL)
+				sqlite3_bind_int(stmt, 7, cache->black_regex_idx);
+			else
+				sqlite3_bind_null(stmt, 7);
+		}
+
 		// Increment status counters
 		switch(status)
 		{
@@ -457,9 +509,9 @@ void DB_read_queries(void)
 			case QUERY_EXTERNAL_BLOCKED_IP: // Blocked by external provider
 			case QUERY_EXTERNAL_BLOCKED_NULL: // Blocked by external provider
 			case QUERY_EXTERNAL_BLOCKED_NXRA: // Blocked by external provider
-			case QUERY_GRAVITY_CNAME: // Blocked by gravity
-			case QUERY_REGEX_CNAME: // Blocked by regex blacklist
-			case QUERY_BLACKLIST_CNAME: // Blocked by exact blacklist
+			case QUERY_GRAVITY_CNAME: // Blocked by gravity (inside CNAME path)
+			case QUERY_REGEX_CNAME: // Blocked by regex blacklist (inside CNAME path)
+			case QUERY_BLACKLIST_CNAME: // Blocked by exact blacklist (inside CNAME path)
 				counters->blocked++;
 				// Get domain pointer
 				domainsData* domain = getDomain(domainID, true);
@@ -1965,22 +1965,7 @@ void _log_query(unsigned int flags, char *name, union all_addr *addr, char *arg,
  if (strlen(name) == 0)
    name = ".";
 /************************************************************** Pi-hole modification  **************************************************************/
-if(debug_dnsmasq_lines == 0)
-{
-/***************************************************************************************************************************************************/
-  if (option_bool(OPT_EXTRALOG))
-    {
-      int port = prettyprint_addr(daemon->log_source_addr, daemon->addrbuff2);
-      if (flags & F_NOEXTRA)
-	my_syslog(LOG_INFO, "* %s/%u %s %s %s %s", daemon->addrbuff2, port, source, name, verb, dest);
-      else
-	my_syslog(LOG_INFO, "%u %s/%u %s %s %s %s", daemon->log_display_id, daemon->addrbuff2, port, source, name, verb, dest);
-    }
-  else
-    my_syslog(LOG_INFO, "%s %s %s %s", source, name, verb, dest);
-/************************************************************** Pi-hole modification  **************************************************************/
-}
-else
+if(debug_dnsmasq_lines != 0)
 {
  if (option_bool(OPT_EXTRALOG))
    {
@@ -1992,8 +1977,20 @@ else
    }
  else
    my_syslog(LOG_INFO, "%s %s %s %s (%s:%d)", source, name, verb, dest, file, line);
+
+  return;
 }
 /***************************************************************************************************************************************************/
+  if (option_bool(OPT_EXTRALOG))
+    {
+      int port = prettyprint_addr(daemon->log_source_addr, daemon->addrbuff2);
+      if (flags & F_NOEXTRA)
+	my_syslog(LOG_INFO, "* %s/%u %s %s %s %s", daemon->addrbuff2, port, source, name, verb, dest);
+      else
+	my_syslog(LOG_INFO, "%u %s/%u %s %s %s %s", daemon->log_display_id, daemon->addrbuff2, port, source, name, verb, dest);
+    }
+  else
+    my_syslog(LOG_INFO, "%s %s %s %s", source, name, verb, dest);
 }

 
@@ -785,8 +785,10 @@ int extract_addresses(struct dns_header *header, size_t qlen, char *name, time_t
 		  // ****************************** Pi-hole modification ******************************
 		  if(FTL_CNAME(name, cpp, daemon->log_display_id))
 		    {
-		      // This query is to be blocked as we found a blocked domain while walking
-		      // the CNAME path.
+		      // This query is to be blocked as we found a blocked
+		      // domain while walking the CNAME path.
+		      // Log to pihole.log: "cached domainabc.com is blocked (Pi-hole CNAME inspection)"
+		      log_query(F_UPSTREAM, name, NULL, "blocked during CNAME inspection");
 		      return 2;
 		    }
 		  // **********************************************************************************
@@ -1817,6 +1819,15 @@ size_t answer_request(struct dns_header *header, char *limit, size_t qlen,
 				FTL_cache(crecp->flags & ~F_REVERSE, name, &crecp->addr,
 				          record_source(crecp->uid),
 				          daemon->log_display_id);
+				// ****************************** Pi-hole modification ******************************
+				if(FTL_CNAME(name, crecp, daemon->log_display_id))
+		  		  {
+		  		    // This query is to be blocked as we found a blocked domain while walking the CNAME path.
+		  		    // Log to pihole.log: "cached domainabc.com is blocked (Pi-hole CNAME inspection)"
+		  		    log_query(F_UPSTREAM, name, NULL, "blocked during CNAME inspection");
+		  		    break;
+		  		  }
+				// **********************************************************************************
 				
 				if (add_resource_record(header, limit, &trunc, nameoffset, &ansp, 
 							crec_ttl(crecp, now), NULL, type, C_IN, 
@@ -63,14 +63,14 @@ char debug_dnsmasq_lines = 0;
 unsigned char* pihole_privacylevel = &config.privacylevel;
 const char flagnames[][12] = {"F_IMMORTAL ", "F_NAMEP ", "F_REVERSE ", "F_FORWARD ", "F_DHCP ", "F_NEG ", "F_HOSTS ", "F_IPV4 ", "F_IPV6 ", "F_BIGNAME ", "F_NXDOMAIN ", "F_CNAME ", "F_DNSKEY ", "F_CONFIG ", "F_DS ", "F_DNSSECOK ", "F_UPSTREAM ", "F_RRNAME ", "F_SERVER ", "F_QUERY ", "F_NOERR ", "F_AUTH ", "F_DNSSEC ", "F_KEYTAG ", "F_SECSTAT ", "F_NO_RR ", "F_IPSET ", "F_NOEXTRA ", "F_SERVFAIL", "F_RCODE"};

-static bool check_domain_blocked(const char *domainString, const int clientID,
+static bool check_domain_blocked(const char *domain, const int clientID,
                                 clientsData *client, queriesData *query, DNSCacheData *dns_cache,
                                 const char **blockingreason, unsigned char *new_status)
 {
 	// Check domains against exact blacklist
 	// Skipped when the domain is whitelisted
 	bool blockDomain = false;
-	if(in_blacklist(domainString, clientID, client))
+	if(in_blacklist(domain, clientID, client))
 	{
 		// We block this domain
 		blockDomain = true;
@@ -85,7 +85,7 @@ static bool check_domain_blocked(const char *domainString, const int clientID,
 	// Check domains against gravity domains
 	// Skipped when the domain is whitelisted or blocked by exact blacklist
 	if(!query->whitelisted && !blockDomain &&
-	   in_gravity(domainString, clientID, client))
+	   in_gravity(domain, clientID, client))
 	{
 		// We block this domain
 		blockDomain = true;
@@ -101,7 +101,7 @@ static bool check_domain_blocked(const char *domainString, const int clientID,
 	// Skipped when the domain is whitelisted or blocked by exact blacklist or gravity
 	int regex_idx = 0;
 	if(!query->whitelisted && !blockDomain &&
-	   (regex_idx = match_regex(domainString, clientID, REGEX_BLACKLIST)) > -1)
+	   (regex_idx = match_regex(domain, clientID, REGEX_BLACKLIST)) > -1)
 	{
 		// We block this domain
 		blockDomain = true;
@@ -166,7 +166,7 @@ static bool _FTL_check_blocking(int queryID, int domainID, int clientID, const c
 			}

 			// Do not block if the entire query is to be permitted
-			// as sometving along the CNAME path hit the whitelist
+			// as something along the CNAME path hit the whitelist
 			if(!query->whitelisted)
 			{
 				query_blocked(query, domain, client, QUERY_BLACKLIST);
@@ -253,27 +253,27 @@ static bool _FTL_check_blocking(int queryID, int domainID, int clientID, const c
 	}

 	// Check whitelist (exact + regex) for match
-	const char *domainString = getstr(domain->domainpos);
-	const char *blockedDomain = domainString;
-	query->whitelisted = in_whitelist(domainString, clientID, client);
+	const char *blockedDomain = domainstr;
+	query->whitelisted = in_whitelist(domainstr, clientID, client);

 	bool blockDomain = false;
 	unsigned char new_status = QUERY_UNKNOWN;
+
 	// Check blacklist (exact + regex) and gravity for queried domain
 	if(!query->whitelisted)
 	{
-	    blockDomain = check_domain_blocked(domainString, clientID, client, query, dns_cache, blockingreason, &new_status);
+		blockDomain = check_domain_blocked(domainstr, clientID, client, query, dns_cache, blockingreason, &new_status);
 	}

 	// Check blacklist (exact + regex) and gravity for _esni.domain if enabled (defaulting to true)
-	if(config.block_esni && !query->whitelisted && !blockDomain && strncasecmp(domainString, "_esni.", 6u) == 0)
+	if(config.block_esni && !query->whitelisted && !blockDomain && strncasecmp(domainstr, "_esni.", 6u) == 0)
 	{
-		blockDomain = check_domain_blocked(domainString + 6u, clientID, client, query, dns_cache, blockingreason, &new_status);
+		blockDomain = check_domain_blocked(domainstr + 6u, clientID, client, query, dns_cache, blockingreason, &new_status);

 		if(blockDomain)
 		{
 			// Truncate "_esni." from queried domain if the parenting domain was the reason for blocking this query
-			blockedDomain = domainString + 6u;
+			blockedDomain = domainstr + 6u;
 			// Force next DNS reply to be NXDOMAIN for _esni.* queries
 			force_next_DNS_reply = NXDOMAIN;
 			dns_cache->force_reply = NXDOMAIN;
@@ -288,7 +288,7 @@ static bool _FTL_check_blocking(int queryID, int domainID, int clientID, const c

 		// Debug output
 		if(config.debug & DEBUG_QUERIES)
-			logg("Blocking %s as %s is %s", domainString, blockedDomain, *blockingreason);
+			logg("Blocking %s as %s is %s", domainstr, blockedDomain, *blockingreason);
 	}
 	else
 	{
@@ -338,35 +338,40 @@ bool _FTL_CNAME(const char *domain, const struct crec *cpp, const int id, const
 		return false;
 	}

-	// Go through already knows domains and see if it is one of them
-	// As this domain might have been found in the middle of a CNAME-path,
-	// it may be not have been seen by FTL_new_query() before
-	char *domainString = strdup(domain);
-	strtolower(domainString);
-	const int domainID = findDomainID(domainString, false);
+	// Example to make the terminology used in here clear:
+	// CNAME abc -> 123
+	// CNAME 123 -> 456
+	// CNAME 456 -> 789
+	// parent_domain: abc
+	// child_domains: [123, 456, 789]

-	// Get client ID from original query
+	// parent_domain = Domain at the top of the CNAME path
+	// This is the domain which was queried first in this chain
+	const int parent_domainID = query->domainID;
+
+	// child_domain = Intermediate domain in CNAME path
+	// This is the domain which was queried later in this chain
+	char *child_domain = strdup(domain);
+	// Convert to lowercase for matching
+	strtolower(child_domain);
+	const int child_domainID = findDomainID(child_domain, false);
+
+	// Get client ID from the original query (the entire chain always
+	// belongs to the same client)
 	const int clientID = query->clientID;

-	// Perform per-client blocking evaluation for this domain. The result for this
-	// domain-client combination will be cached to be immediately available for later
-	// queries of the same domain by the same client
+	// Check per-client blocking for the child domain
 	const char *blockingreason = NULL;
-	bool block = FTL_check_blocking(queryID, domainID, clientID, &blockingreason);
+	const bool block = FTL_check_blocking(queryID, child_domainID, clientID, &blockingreason);

 	// If we find during a CNAME inspection that we want to block the entire chain,
-	// the originally queried domain itself was not counted as blocked (but as
-	// (permitted). Later in the chain, when we find that this is a bad guy, we
-	// short-circuit it. We need to correct the domain counter of the domain at the
-	// head of the chain, otherwise, the data for the top lists is misleading.
-	// For this, we go back the entire path and change the original request to blocked
-	// by increasing the blocked count of this domain by one. Fortunately, each CNAME
-	// path can easily be tracked back to the original head in FTL's data so we do not
-	// need to search it. This makes the change able to happen without causing any delay.
+	// the originally queried domain itself was not counted as blocked. We have to
+	// correct this when we are going to short-circuit the entire query
 	if(block)
 	{
-		domainsData* head_domain = getDomain(query->domainID, true);
-		head_domain->blockedcount++;
+		// Increase blocked count of parent domain
+		domainsData* parent_domain = getDomain(parent_domainID, true);
+		parent_domain->blockedcount++;

 		// Store query response as CNAME type
 		struct timeval response;
@@ -374,29 +379,37 @@ bool _FTL_CNAME(const char *domain, const struct crec *cpp, const int id, const
 		save_reply_type(F_CNAME, NULL, query, response);

 		// Store domain that was the reason for blocking the entire chain
-		query->CNAME_domainID = domainID;
+		query->CNAME_domainID = child_domainID;

 		// Change blocking reason into CNAME-caused blocking
 		if(query->status == QUERY_GRAVITY)
+		{
 			query->status = QUERY_GRAVITY_CNAME;
+		}
 		else if(query->status == QUERY_REGEX)
 		{
 			// Get parent and child DNS cache entries
-			unsigned int parent_cacheID = findCacheID(domainID, query->clientID);
-			unsigned int child_cacheID = findCacheID(query->domainID, query->clientID);
+			const int parent_cacheID = findCacheID(parent_domainID, clientID);
+			const int child_cacheID = findCacheID(child_domainID, clientID);

 			// Get cache pointers
-			DNSCacheData *parent_dns_cache = getDNSCache(parent_cacheID, true);
-			DNSCacheData *child_dns_cache = getDNSCache(child_cacheID, true);
+			DNSCacheData *parent_cache = getDNSCache(parent_cacheID, true);
+			DNSCacheData *child_cache = getDNSCache(child_cacheID, true);

 			// Propagate ID of responsible regex up from the child to the parent domain
-			if(parent_dns_cache != NULL && child_dns_cache != NULL)
-				child_dns_cache->black_regex_idx = parent_dns_cache->black_regex_idx;
+			if(parent_cache != NULL && child_cache != NULL)
+			{
+				child_cache->black_regex_idx = parent_cache->black_regex_idx;
+			}

+			// Set status
 			query->status = QUERY_REGEX_CNAME;
 		}
 		else if(query->status == QUERY_BLACKLIST)
+		{
+			// Only set status
 			query->status = QUERY_BLACKLIST_CNAME;
+		}
 	}

 	// Debug logging for deep CNAME inspection (if enabled)
@@ -409,7 +422,7 @@ bool _FTL_CNAME(const char *domain, const struct crec *cpp, const int id, const
 	}

 	// Return result
-	free(domainString);
+	free(child_domain);
 	unlock_shm();
 	return block;
 }
@@ -339,7 +339,7 @@
@test "pihole-FTL.db schema as expected" {
  run bash -c 'sqlite3 /etc/pihole/pihole-FTL.db .dump'
  printf "%s\n" "${lines[@]}"
-  [[ "${lines[@]}" == *"CREATE TABLE queries ( id INTEGER PRIMARY KEY AUTOINCREMENT, timestamp INTEGER NOT NULL, type INTEGER NOT NULL, status INTEGER NOT NULL, domain TEXT NOT NULL, client TEXT NOT NULL, forward TEXT );"* ]]
+  [[ "${lines[@]}" == *"CREATE TABLE queries ( id INTEGER PRIMARY KEY AUTOINCREMENT, timestamp INTEGER NOT NULL, type INTEGER NOT NULL, status INTEGER NOT NULL, domain TEXT NOT NULL, client TEXT NOT NULL, forward TEXT , additional_info TEXT);"* ]]
  [[ "${lines[@]}" == *"CREATE TABLE ftl ( id INTEGER PRIMARY KEY NOT NULL, value BLOB NOT NULL );"* ]]
  [[ "${lines[@]}" == *"CREATE TABLE counters ( id INTEGER PRIMARY KEY NOT NULL, value INTEGER NOT NULL );"* ]]
  [[ "${lines[@]}" == *"CREATE TABLE IF NOT EXISTS \"network\" ( id INTEGER PRIMARY KEY NOT NULL, hwaddr TEXT UNIQUE NOT NULL, interface TEXT NOT NULL, name TEXT, firstSeen INTEGER NOT NULL, lastQuery INTEGER NOT NULL, numQueries INTEGER NOT NULL, macVendor TEXT);"* ]]