Merge branch 'topic/johanna/gh-744-cache-the-heck-out-of-these-certs'

* topic/johanna/gh-744-cache-the-heck-out-of-these-certs:
  X509 caching API change: callback gets entry directly
  Address feedback
  Small default updates & external baselines.
  X509 caching: small API changes, tests & test updates
  Certificate caching - now working in principle.
  First (sadly not completely working) approach at caching X509 certificates

CHANGES

@@ -1,4 +1,23 @@
 
+3.2.0-dev.230 | 2020-03-12 13:33:09 -0700
+
+  * Introduce X509 certificate caching.
+
+    This change introduces caching of X509 certificates. If a certificate is
+    encountered more than 10 times in a minute, it will be cached for the future
+    (until it is not seen for more than a minute). The caching means that the
+    base scripts cache the certificate information and use cached information
+    to raise events.
+
+    This means certificates do not have to be repeatedly parsed; furthermore
+    the events are passed "recycled" Vals (so data is not repeatedly copied around).
+
+    This new feature is highly configureable - see the x509 main.zeek for full
+    information. You can both change the timeouts, disable the feature, or
+    even stop X509 events from being raised (by hooking X509::x509_certificate_cache_replay).
+
+    (Johanna Amann, Corelight)
+
 3.2.0-dev.223 | 2020-03-12 12:03:48 -0700
 
   * Update pointer to external test repo (Jon Siwek, Corelight)

NEWS

@@ -9,6 +9,20 @@ Zeek 3.2.0
 New Functionality
 -----------------
 
+- X509 Certificate caching:
+
+  Zeek now caches certificates if they have (by default) been encountered
+	more than 10 times in 62 seconds. Information for cached certificates is
+	retained; if the certificate is encountered again it does not have to
+	be re-parsed and already existing information is used to raise the events.
+
+	This should especially help with performance in environments where the
+	same certificates are seen very often.
+
+	Certificate caching is very configureable; it is possible to disable the
+	feature, change the time intervals or even suppress X509 events.
+	For details see ``scripts/base/files/x509/main.zeek``.
+
 Changed Functionality
 ---------------------
 

VERSION

@@ -1 +1 @@
-3.2.0-dev.223
+3.2.0-dev.230

doc

@@ -1 +1 @@
-Subproject commit 2a392358301a638fb5d8cded2db96941a2131482
+Subproject commit 61a7ba44ff98021fcbe5bd5fe0888dbd3d45d2b5

scripts/base/files/x509/main.zeek

@@ -6,6 +6,20 @@ module X509;
 export {
 	redef enum Log::ID += { LOG };
 
+	## How often do you have to encounter a certificate before
+	## caching it. Set to 0 to disable caching of certificates.
+	option caching_required_encounters : count = 10;
+
+	## The timespan over which caching_required_encounters has to be reached
+	option caching_required_encounters_interval : interval = 62 secs;
+
+	## After a certificate has not been encountered for this time, it
+	## may be evicted from the certificate cache.
+	option certificate_cache_minimum_eviction_interval : interval = 62 secs;
+
+	## Maximum size of the certificate cache
+	option certificate_cache_max_entries : count = 10000;
+
 	## The record type which contains the fields of the X.509 log.
 	type Info: record {
 		## Current timestamp.
@@ -23,12 +37,58 @@ export {
 		san: X509::SubjectAlternativeName &optional &log;
 		## Basic constraints extension of the certificate.
 		basic_constraints: X509::BasicConstraints &optional &log;
+		## All extensions in the order they were raised.
+		## This is used for caching certificates that are commonly
+		## encountered and should not be relied on in user scripts.
+		extensions_cache: vector of any &default=vector();
 	};
 
+	## This record is used to store information about the SCTs that are
+	## encountered in Certificates.
+	type SctInfo: record {
+		## The version of the encountered SCT (should always be 0 for v1).
+		version: count;
+		## The ID of the log issuing this SCT.
+		logid: string;
+		## The timestamp at which this SCT was issued measured since the
+		## epoch (January 1, 1970, 00:00), ignoring leap seconds, in
+		## milliseconds. Not converted to a Zeek timestamp because we need
+		## the exact value for validation.
+		timestamp: count;
+		## The hash algorithm used for this sct.
+		hash_alg: count;
+		## The signature algorithm used for this sct.
+		sig_alg: count;
+		## The signature of this SCT.
+		signature: string;
+	};
+
+	## This hook performs event-replays in case a certificate that already
+	## is in the cache is encountered.
+	##
+	## It is possible to change this behavior/skip sending the events by
+	## installing a higher priority hook instead.
+	global x509_certificate_cache_replay: hook(f: fa_file, e: X509::Info, sha256: string);
+
 	## Event for accessing logged records.
 	global log_x509: event(rec: Info);
 }
 
+# Table tracking potential certificates to cache - indexed by the SHA256 of the
+# raw on-the-wire representation (DER).
+global certificates_encountered: table[string] of count &create_expire=caching_required_encounters_interval;
+
+# Table caching the output of the X509 analyzer for commonly seen certificates.
+# This is indexed by SHA256 and contains the Info record of the first certificate
+# encountered. We use this info record to re-play the events.
+global certificate_cache: table[string] of X509::Info &read_expire=certificate_cache_minimum_eviction_interval;
+
+redef record Files::Info += {
+	## Information about X509 certificates. This is used to keep
+	## certificate information until all events have been received.
+	x509: X509::Info &optional;
+};
+
 event zeek_init() &priority=5
 	{
 	Log::create_stream(X509::LOG, [$columns=Info, $ev=log_x509, $path="x509"]);
@@ -50,13 +110,46 @@ event zeek_init() &priority=5
 	Files::register_for_mime_type(Files::ANALYZER_SHA1, "application/x-x509-user-cert");
 	Files::register_for_mime_type(Files::ANALYZER_SHA1, "application/x-x509-ca-cert");
 	Files::register_for_mime_type(Files::ANALYZER_SHA1, "application/pkix-cert");
+
+	# SHA256 is used by us to determine which certificates to cache.
+	Files::register_for_mime_type(Files::ANALYZER_SHA256, "application/x-x509-user-cert");
+	Files::register_for_mime_type(Files::ANALYZER_SHA256, "application/x-x509-ca-cert");
+	Files::register_for_mime_type(Files::ANALYZER_SHA256, "application/pkix-cert");
+
+	x509_set_certificate_cache(certificate_cache);
+	x509_set_certificate_cache_hit_callback(x509_certificate_cache_replay);
 	}
 
-redef record Files::Info += {
+hook x509_certificate_cache_replay(f: fa_file, e: X509::Info, sha256: string)
-	## Information about X509 certificates. This is used to keep
+	{
-	## certificate information until all events have been received.
+	# we encountered a cached cert. The X509 analyzer will skip it. Let's raise all the events that it typically
-	x509: X509::Info &optional;
+	# raises by ourselfes.
-};
+
+	# first - let's checked if it already has an x509 record. That would mean that someone raised the file_hash event
+	# several times for the certificate - in which case we bail out.
+	if ( f$info?$x509 )
+		return;
+
+	event x509_certificate(f, e$handle, e$certificate);
+	for ( i in e$extensions_cache )
+		{
+		local ext = e$extensions_cache[i];
+
+		if ( ext is X509::Extension )
+			event x509_extension(f, (ext as X509::Extension));
+		else if ( ext is X509::BasicConstraints )
+			event x509_ext_basic_constraints(f, (ext as X509::BasicConstraints));
+		else if ( ext is X509::SubjectAlternativeName )
+			event x509_ext_subject_alternative_name(f, (ext as X509::SubjectAlternativeName));
+		else if ( ext is X509::SctInfo )
+			{
+			local s = ( ext as X509::SctInfo);
+			event x509_ocsp_ext_signed_certificate_timestamp(f, s$version, s$logid, s$timestamp, s$hash_alg, s$sig_alg, s$signature);
+			}
+		else
+			Reporter::error(fmt("Encountered unknown extension while replaying certificate with fuid %s", f$id)); 
+		}
+	}
 
 event x509_certificate(f: fa_file, cert_ref: opaque of x509, cert: X509::Certificate) &priority=5
 	{
@@ -66,19 +159,34 @@ event x509_certificate(f: fa_file, cert_ref: opaque of x509, cert: X509::Certifi
 event x509_extension(f: fa_file, ext: X509::Extension) &priority=5
 	{
 	if ( f$info?$x509 )
+		{
 		f$info$x509$extensions += ext;
+		f$info$x509$extensions_cache += ext;
+		}
 	}
 
 event x509_ext_basic_constraints(f: fa_file, ext: X509::BasicConstraints) &priority=5
 	{
 	if ( f$info?$x509 )
+		{
 		f$info$x509$basic_constraints = ext;
+		f$info$x509$extensions_cache += ext;
+		}
 	}
 
 event x509_ext_subject_alternative_name(f: fa_file, ext: X509::SubjectAlternativeName) &priority=5
 	{
 	if ( f$info?$x509 )
+		{
 		f$info$x509$san = ext;
+		f$info$x509$extensions_cache += ext;
+		}
+	}
+
+event x509_ocsp_ext_signed_certificate_timestamp(f: fa_file, version: count, logid: string, timestamp: count, hash_algorithm: count, signature_algorithm: count, signature: string) &priority=5
+	{
+	if ( f$info?$x509 )
+		f$info$x509$extensions_cache += SctInfo($version=version, $logid=logid, $timestamp=timestamp, $hash_alg=hash_algorithm, $sig_alg=signature_algorithm, $signature=signature);
 	}
 
 event file_state_remove(f: fa_file) &priority=5
@@ -87,4 +195,29 @@ event file_state_remove(f: fa_file) &priority=5
 		return;
 
 	Log::write(LOG, f$info$x509);
+
+	if ( f$info?$sha256 && f$info$sha256 !in certificate_cache &&
+		caching_required_encounters > 0 &&
+		f$info$sha256 in certificates_encountered &&
+		certificates_encountered[f$info$sha256] >= caching_required_encounters &&
+		|certificate_cache| < certificate_cache_max_entries )
+		{
+		delete certificates_encountered[f$info$sha256];
+		certificate_cache[f$info$sha256] = f$info$x509;
+		}
+
+	}
+
+event file_hash(f: fa_file, kind: string, hash: string)
+	{
+	if ( ! f?$info || "X509" !in f$info$analyzers || kind != "sha256" )
+		return;
+
+	if ( caching_required_encounters == 0 || hash in certificate_cache )
+		return;
+
+	if ( hash !in certificates_encountered )
+		certificates_encountered[hash] = 1;
+	else
+		certificates_encountered[hash] += 1;
 	}

scripts/base/init-bare.zeek

@@ -11,6 +11,13 @@
 ##    directly and then remove this alias.
 type string_array: table[count] of string;
 
+## A string-table of any.
+##
+## .. todo:: We need this type definition only for declaring builtin functions
+##    via ``bifcl``. We should extend ``bifcl`` to understand composite types
+##    directly and then remove this alias.
+type string_any_table: table[string] of any;
+
 ## A set of strings.
 ##
 ## .. todo:: We need this type definition only for declaring builtin functions
@@ -505,6 +512,13 @@ type fa_file: record {
 	bof_buffer: string &optional;
 } &redef;
 
+## A hook taking a fa_file, an any, and a string. Used by the X509 analyzer as callback.
+##
+## .. todo:: We need this type definition only for declaring builtin functions
+##    via ``bifcl``. We should extend ``bifcl`` to understand composite types
+##    directly and then remove this alias.
+type string_any_file_hook: hook(f: fa_file, e: any, str: string);
+
 ## Metadata that's been inferred about a particular file.
 type fa_metadata: record {
 	## The strongest matching MIME type if one was discovered.

src/file_analysis/analyzer/x509/X509.cc

@@ -19,10 +19,6 @@
 #include <openssl/opensslconf.h>
 #include <openssl/err.h>
 
-namespace file_analysis {
-std::map<Val*, X509_STORE*> X509::x509_stores;
-}
-
 using namespace file_analysis;
 
 file_analysis::X509::X509(RecordVal* args, file_analysis::File* file)
@@ -45,10 +41,36 @@ bool file_analysis::X509::Undelivered(uint64_t offset, uint64_t len)
 
 bool file_analysis::X509::EndOfFile()
 	{
+	const unsigned char* cert_char = reinterpret_cast<const unsigned char*>(cert_data.data());
+	if ( certificate_cache )
+		{
+		// first step - let's see if the certificate has been cached.
+		unsigned char buf[SHA256_DIGEST_LENGTH];
+		auto ctx = hash_init(Hash_SHA256);
+		hash_update(ctx, cert_char, cert_data.size());
+		hash_final(ctx, buf);
+		std::string cert_sha256 = sha256_digest_print(buf);
+		auto index = make_intrusive<StringVal>(cert_sha256);
+		auto* entry = certificate_cache->Lookup(index.get(), false);
+		if ( entry )
+			// in this case, the certificate is in the cache and we do not
+			// do any further processing here. However, if there is a callback, we execute it.
+			{
+			if ( ! cache_hit_callback )
+				return false;
+			// yup, let's call the callback.
+
+			val_list vl(3);
+			vl.push_back(GetFile()->GetVal()->Ref());
+			vl.push_back(entry->Ref());
+			vl.push_back(new StringVal(cert_sha256));
+			IntrusivePtr<Val> v{AdoptRef{}, cache_hit_callback->Call(&vl)};
+			return false;
+			}
+		}
+
 	// ok, now we can try to parse the certificate with openssl. Should
 	// be rather straightforward...
-	const unsigned char* cert_char = reinterpret_cast<const unsigned char*>(cert_data.data());
-
 	::X509* ssl_cert = d2i_X509(NULL, &cert_char, cert_data.size());
 	if ( ! ssl_cert )
 		{

src/file_analysis/analyzer/x509/X509.h

@@ -7,6 +7,7 @@
 
 #include "OpaqueVal.h"
 #include "X509Common.h"
+#include "Func.h"
 
 #if ( OPENSSL_VERSION_NUMBER < 0x10002000L ) || defined(LIBRESSL_VERSION_NUMBER)
 
@@ -112,6 +113,18 @@ public:
 	 */
 	static void FreeRootStore();
 
+	/**
+	 * Sets the table[string] that used as the certificate cache inside of Zeek.
+	 */
+	static void SetCertificateCache(IntrusivePtr<TableVal> cache)
+		{ certificate_cache = std::move(cache); }
+
+	/**
+	 * Sets the callback when a certificate cache hit is encountered
+	 */
+	static void SetCertificateCacheHitCallback(IntrusivePtr<Func> func)
+		{ cache_hit_callback = std::move(func); }
+
 protected:
 	X509(RecordVal* args, File* file);
 
@@ -126,7 +139,9 @@ private:
 	static StringVal* KeyCurve(EVP_PKEY *key);
 	static unsigned int KeyLength(EVP_PKEY *key);
 	/** X509 stores associated with global script-layer values */
-	static std::map<Val*, X509_STORE*> x509_stores;
+	inline static std::map<Val*, X509_STORE*> x509_stores = std::map<Val*, X509_STORE*>();
+	inline static IntrusivePtr<TableVal> certificate_cache = nullptr;
+	inline static IntrusivePtr<Func> cache_hit_callback = nullptr;
 };
 
 /**

src/file_analysis/analyzer/x509/functions.bif

@@ -881,3 +881,44 @@ function x509_spki_hash%(cert: opaque of x509, hash_alg: count%): string
 
 	return x509_entity_hash(cert_handle, hash_alg, 2);
 	%}
+
+## This function can be used to set up certificate caching. It has to be passed a table[string] which
+## can contain any type.
+##
+## After this is set up, for each certificate encountered, the X509 analyzer will check if the entry
+## tbl[sha256 of certificate] is set. If this is the case, the X509 analyzer will skip all further
+## processing, and instead just call the callback that is set with
+## zeek:id:`x509_set_certificate_cache_hit_callback`.
+##
+## tbl: Table to use as the certificate cache.
+##
+## Returns: Always returns true.
+##
+## .. note:: The base scripts use this function to set up certificate caching. You should only change the
+##           cache table if you are sure you will not conflict with the base scripts.
+##
+## .. zeek:see:: x509_set_certificate_cache_hit_callback
+function x509_set_certificate_cache%(tbl: string_any_table%) : bool
+	%{
+	file_analysis::X509::SetCertificateCache({NewRef{}, tbl->AsTableVal()});
+
+	return val_mgr->GetTrue();
+	%}
+
+## This function sets up the callback that is called when an entry is matched against the table set
+## by :zeek:id:`x509_set_certificate_cache`.
+##
+## f: The callback that will be called when encountering a certificate in the cache table.
+##
+## Returns: Always returns true.
+##
+## .. note:: The base scripts use this function to set up certificate caching. You should only change the
+##           callback function if you are sure you will not conflict with the base scripts.
+##
+## .. zeek:see:: x509_set_certificate_cache
+function x509_set_certificate_cache_hit_callback%(f: string_any_file_hook%) : bool
+	%{
+	file_analysis::X509::SetCertificateCacheHitCallback({NewRef{}, f->AsFunc()});
+
+	return val_mgr->GetTrue();
+	%}

testing/btest/Baseline/language.expire_subnet/output

@@ -15,13 +15,13 @@ Accessed table nums: two; three
 Accessed table nets: two; zero, three
 Time: 7.0 secs 518.0 msecs 828.15361 usecs
 
-Expired Subnet: 192.168.4.0/24 --> four at 8.0 secs 835.0 msecs 30.078888 usecs
-Expired Subnet: 192.168.1.0/24 --> one at 8.0 secs 835.0 msecs 30.078888 usecs
 Expired Num: 4 --> four at 8.0 secs 835.0 msecs 30.078888 usecs
 Expired Num: 1 --> one at 8.0 secs 835.0 msecs 30.078888 usecs
 Expired Num: 0 --> zero at 8.0 secs 835.0 msecs 30.078888 usecs
+Expired Subnet: 192.168.4.0/24 --> four at 8.0 secs 835.0 msecs 30.078888 usecs
+Expired Subnet: 192.168.1.0/24 --> one at 8.0 secs 835.0 msecs 30.078888 usecs
+Expired Num: 2 --> two at 15.0 secs 150.0 msecs 681.018829 usecs
+Expired Num: 3 --> three at 15.0 secs 150.0 msecs 681.018829 usecs
 Expired Subnet: 192.168.0.0/16 --> zero at 15.0 secs 150.0 msecs 681.018829 usecs
 Expired Subnet: 192.168.3.0/24 --> three at 15.0 secs 150.0 msecs 681.018829 usecs
 Expired Subnet: 192.168.2.0/24 --> two at 15.0 secs 150.0 msecs 681.018829 usecs
-Expired Num: 2 --> two at 15.0 secs 150.0 msecs 681.018829 usecs
-Expired Num: 3 --> three at 15.0 secs 150.0 msecs 681.018829 usecs

testing/btest/Baseline/plugins.hooks/output

@@ -173,6 +173,9 @@
 0.000000   MetaHookPost  CallFunction(Files::register_for_mime_type, <frame>, (Files::ANALYZER_SHA1, application/pkix-cert)) -> <no result>
 0.000000   MetaHookPost  CallFunction(Files::register_for_mime_type, <frame>, (Files::ANALYZER_SHA1, application/x-x509-ca-cert)) -> <no result>
 0.000000   MetaHookPost  CallFunction(Files::register_for_mime_type, <frame>, (Files::ANALYZER_SHA1, application/x-x509-user-cert)) -> <no result>
+0.000000   MetaHookPost  CallFunction(Files::register_for_mime_type, <frame>, (Files::ANALYZER_SHA256, application/pkix-cert)) -> <no result>
+0.000000   MetaHookPost  CallFunction(Files::register_for_mime_type, <frame>, (Files::ANALYZER_SHA256, application/x-x509-ca-cert)) -> <no result>
+0.000000   MetaHookPost  CallFunction(Files::register_for_mime_type, <frame>, (Files::ANALYZER_SHA256, application/x-x509-user-cert)) -> <no result>
 0.000000   MetaHookPost  CallFunction(Files::register_for_mime_type, <frame>, (Files::ANALYZER_X509, application/pkix-cert)) -> <no result>
 0.000000   MetaHookPost  CallFunction(Files::register_for_mime_type, <frame>, (Files::ANALYZER_X509, application/x-x509-ca-cert)) -> <no result>
 0.000000   MetaHookPost  CallFunction(Files::register_for_mime_type, <frame>, (Files::ANALYZER_X509, application/x-x509-user-cert)) -> <no result>
@@ -276,7 +279,7 @@
 0.000000   MetaHookPost  CallFunction(Log::__create_stream, <frame>, (Weird::LOG, [columns=Weird::Info, ev=Weird::log_weird, path=weird])) -> <no result>
 0.000000   MetaHookPost  CallFunction(Log::__create_stream, <frame>, (X509::LOG, [columns=X509::Info, ev=X509::log_x509, path=x509])) -> <no result>
 0.000000   MetaHookPost  CallFunction(Log::__create_stream, <frame>, (mysql::LOG, [columns=MySQL::Info, ev=MySQL::log_mysql, path=mysql])) -> <no result>
-0.000000   MetaHookPost  CallFunction(Log::__write, <frame>, (PacketFilter::LOG, [ts=1580932537.132762, node=zeek, filter=ip or not ip, init=T, success=T])) -> <no result>
+0.000000   MetaHookPost  CallFunction(Log::__write, <frame>, (PacketFilter::LOG, [ts=1584045167.489534, node=zeek, filter=ip or not ip, init=T, success=T])) -> <no result>
 0.000000   MetaHookPost  CallFunction(Log::add_default_filter, <frame>, (Broker::LOG)) -> <no result>
 0.000000   MetaHookPost  CallFunction(Log::add_default_filter, <frame>, (Cluster::LOG)) -> <no result>
 0.000000   MetaHookPost  CallFunction(Log::add_default_filter, <frame>, (Config::LOG)) -> <no result>
@@ -457,7 +460,7 @@
 0.000000   MetaHookPost  CallFunction(Log::create_stream, <frame>, (Weird::LOG, [columns=Weird::Info, ev=Weird::log_weird, path=weird])) -> <no result>
 0.000000   MetaHookPost  CallFunction(Log::create_stream, <frame>, (X509::LOG, [columns=X509::Info, ev=X509::log_x509, path=x509])) -> <no result>
 0.000000   MetaHookPost  CallFunction(Log::create_stream, <frame>, (mysql::LOG, [columns=MySQL::Info, ev=MySQL::log_mysql, path=mysql])) -> <no result>
-0.000000   MetaHookPost  CallFunction(Log::write, <frame>, (PacketFilter::LOG, [ts=1580932537.132762, node=zeek, filter=ip or not ip, init=T, success=T])) -> <no result>
+0.000000   MetaHookPost  CallFunction(Log::write, <frame>, (PacketFilter::LOG, [ts=1584045167.489534, node=zeek, filter=ip or not ip, init=T, success=T])) -> <no result>
 0.000000   MetaHookPost  CallFunction(NetControl::check_plugins, <frame>, ()) -> <no result>
 0.000000   MetaHookPost  CallFunction(NetControl::init, <null>, ()) -> <no result>
 0.000000   MetaHookPost  CallFunction(Notice::want_pp, <frame>, ()) -> <no result>
@@ -535,6 +538,10 @@
 0.000000   MetaHookPost  CallFunction(Option::set_change_handler, <frame>, (Weird::sampling_whitelist, Config::config_option_changed{ Config::log = (coerce [$ts=network_time(), $id=Config::ID, $old_value=Config::format_value(lookup_ID(Config::ID)), $new_value=Config::format_value(Config::new_value)] to Config::Info)if ( != Config::location) Config::log$location = Config::locationLog::write(Config::LOG, Config::log)return (Config::new_value)}, -100)) -> <no result>
 0.000000   MetaHookPost  CallFunction(Option::set_change_handler, <frame>, (Weird::sampling_whitelist, Config::weird_option_change_sampling_whitelist{ if (Weird::sampling_whitelist == Config::ID) { Reporter::set_weird_sampling_whitelist(Config::new_value)}return (Config::new_value)}, 5)) -> <no result>
 0.000000   MetaHookPost  CallFunction(Option::set_change_handler, <frame>, (Weird::weird_do_not_ignore_repeats, Config::config_option_changed{ Config::log = (coerce [$ts=network_time(), $id=Config::ID, $old_value=Config::format_value(lookup_ID(Config::ID)), $new_value=Config::format_value(Config::new_value)] to Config::Info)if ( != Config::location) Config::log$location = Config::locationLog::write(Config::LOG, Config::log)return (Config::new_value)}, -100)) -> <no result>
+0.000000   MetaHookPost  CallFunction(Option::set_change_handler, <frame>, (X509::caching_required_encounters, Config::config_option_changed{ Config::log = (coerce [$ts=network_time(), $id=Config::ID, $old_value=Config::format_value(lookup_ID(Config::ID)), $new_value=Config::format_value(Config::new_value)] to Config::Info)if ( != Config::location) Config::log$location = Config::locationLog::write(Config::LOG, Config::log)return (Config::new_value)}, -100)) -> <no result>
+0.000000   MetaHookPost  CallFunction(Option::set_change_handler, <frame>, (X509::caching_required_encounters_interval, Config::config_option_changed{ Config::log = (coerce [$ts=network_time(), $id=Config::ID, $old_value=Config::format_value(lookup_ID(Config::ID)), $new_value=Config::format_value(Config::new_value)] to Config::Info)if ( != Config::location) Config::log$location = Config::locationLog::write(Config::LOG, Config::log)return (Config::new_value)}, -100)) -> <no result>
+0.000000   MetaHookPost  CallFunction(Option::set_change_handler, <frame>, (X509::certificate_cache_max_entries, Config::config_option_changed{ Config::log = (coerce [$ts=network_time(), $id=Config::ID, $old_value=Config::format_value(lookup_ID(Config::ID)), $new_value=Config::format_value(Config::new_value)] to Config::Info)if ( != Config::location) Config::log$location = Config::locationLog::write(Config::LOG, Config::log)return (Config::new_value)}, -100)) -> <no result>
+0.000000   MetaHookPost  CallFunction(Option::set_change_handler, <frame>, (X509::certificate_cache_minimum_eviction_interval, Config::config_option_changed{ Config::log = (coerce [$ts=network_time(), $id=Config::ID, $old_value=Config::format_value(lookup_ID(Config::ID)), $new_value=Config::format_value(Config::new_value)] to Config::Info)if ( != Config::location) Config::log$location = Config::locationLog::write(Config::LOG, Config::log)return (Config::new_value)}, -100)) -> <no result>
 0.000000   MetaHookPost  CallFunction(Option::set_change_handler, <frame>, (default_file_bof_buffer_size, Config::config_option_changed{ Config::log = (coerce [$ts=network_time(), $id=Config::ID, $old_value=Config::format_value(lookup_ID(Config::ID)), $new_value=Config::format_value(Config::new_value)] to Config::Info)if ( != Config::location) Config::log$location = Config::locationLog::write(Config::LOG, Config::log)return (Config::new_value)}, -100)) -> <no result>
 0.000000   MetaHookPost  CallFunction(Option::set_change_handler, <frame>, (default_file_timeout_interval, Config::config_option_changed{ Config::log = (coerce [$ts=network_time(), $id=Config::ID, $old_value=Config::format_value(lookup_ID(Config::ID)), $new_value=Config::format_value(Config::new_value)] to Config::Info)if ( != Config::location) Config::log$location = Config::locationLog::write(Config::LOG, Config::log)return (Config::new_value)}, -100)) -> <no result>
 0.000000   MetaHookPost  CallFunction(PacketFilter::build, <frame>, ()) -> <no result>
@@ -567,6 +574,8 @@
 0.000000   MetaHookPost  CallFunction(set_to_regex, <frame>, ({}, (^\.?|\.)(~~)$)) -> <no result>
 0.000000   MetaHookPost  CallFunction(string_to_pattern, <frame>, ((^\.?|\.)()$, F)) -> <no result>
 0.000000   MetaHookPost  CallFunction(sub, <frame>, ((^\.?|\.)(~~)$, <...>/, )) -> <no result>
+0.000000   MetaHookPost  CallFunction(x509_set_certificate_cache, <frame>, ({})) -> <no result>
+0.000000   MetaHookPost  CallFunction(x509_set_certificate_cache_hit_callback, <frame>, (X509::x509_certificate_cache_replay{ <init> X509::i{ if (X509::f$info?$x509) return event x509_certificate(X509::f, X509::e$handle, X509::e$certificate)for ([X509::i] in X509::e$extensions_cache) { X509::ext = X509::e$extensions_cache[X509::i]if (X509::ext is X509::Extension) event x509_extension(X509::f, (X509::ext as X509::Extension))elseif (X509::ext is X509::BasicConstraints) event x509_ext_basic_constraints(X509::f, (X509::ext as X509::BasicConstraints))elseif (X509::ext is X509::SubjectAlternativeName) event x509_ext_subject_alternative_name(X509::f, (X509::ext as X509::SubjectAlternativeName))elseif (X509::ext is X509::SctInfo) { X509::s = (X509::ext as X509::SctInfo)event x509_ocsp_ext_signed_certificate_timestamp(X509::f, X509::s$version, X509::s$logid, X509::s$timestamp, X509::s$hash_alg, X509::s$sig_alg, X509::s$signature)}elseReporter::error(fmt(Encountered unknown extension while replaying certificate with fuid %s, X509::f$id))}}})) -> <no result>
 0.000000   MetaHookPost  CallFunction(zeek_init, <null>, ()) -> <no result>
 0.000000   MetaHookPost  DrainEvents() -> <void>
 0.000000   MetaHookPost  LoadFile(0, ..<...>/main.zeek) -> -1
@@ -1077,6 +1086,9 @@
 0.000000   MetaHookPre   CallFunction(Files::register_for_mime_type, <frame>, (Files::ANALYZER_SHA1, application/pkix-cert))
 0.000000   MetaHookPre   CallFunction(Files::register_for_mime_type, <frame>, (Files::ANALYZER_SHA1, application/x-x509-ca-cert))
 0.000000   MetaHookPre   CallFunction(Files::register_for_mime_type, <frame>, (Files::ANALYZER_SHA1, application/x-x509-user-cert))
+0.000000   MetaHookPre   CallFunction(Files::register_for_mime_type, <frame>, (Files::ANALYZER_SHA256, application/pkix-cert))
+0.000000   MetaHookPre   CallFunction(Files::register_for_mime_type, <frame>, (Files::ANALYZER_SHA256, application/x-x509-ca-cert))
+0.000000   MetaHookPre   CallFunction(Files::register_for_mime_type, <frame>, (Files::ANALYZER_SHA256, application/x-x509-user-cert))
 0.000000   MetaHookPre   CallFunction(Files::register_for_mime_type, <frame>, (Files::ANALYZER_X509, application/pkix-cert))
 0.000000   MetaHookPre   CallFunction(Files::register_for_mime_type, <frame>, (Files::ANALYZER_X509, application/x-x509-ca-cert))
 0.000000   MetaHookPre   CallFunction(Files::register_for_mime_type, <frame>, (Files::ANALYZER_X509, application/x-x509-user-cert))
@@ -1180,7 +1192,7 @@
 0.000000   MetaHookPre   CallFunction(Log::__create_stream, <frame>, (Weird::LOG, [columns=Weird::Info, ev=Weird::log_weird, path=weird]))
 0.000000   MetaHookPre   CallFunction(Log::__create_stream, <frame>, (X509::LOG, [columns=X509::Info, ev=X509::log_x509, path=x509]))
 0.000000   MetaHookPre   CallFunction(Log::__create_stream, <frame>, (mysql::LOG, [columns=MySQL::Info, ev=MySQL::log_mysql, path=mysql]))
-0.000000   MetaHookPre   CallFunction(Log::__write, <frame>, (PacketFilter::LOG, [ts=1580932537.132762, node=zeek, filter=ip or not ip, init=T, success=T]))
+0.000000   MetaHookPre   CallFunction(Log::__write, <frame>, (PacketFilter::LOG, [ts=1584045167.489534, node=zeek, filter=ip or not ip, init=T, success=T]))
 0.000000   MetaHookPre   CallFunction(Log::add_default_filter, <frame>, (Broker::LOG))
 0.000000   MetaHookPre   CallFunction(Log::add_default_filter, <frame>, (Cluster::LOG))
 0.000000   MetaHookPre   CallFunction(Log::add_default_filter, <frame>, (Config::LOG))
@@ -1361,7 +1373,7 @@
 0.000000   MetaHookPre   CallFunction(Log::create_stream, <frame>, (Weird::LOG, [columns=Weird::Info, ev=Weird::log_weird, path=weird]))
 0.000000   MetaHookPre   CallFunction(Log::create_stream, <frame>, (X509::LOG, [columns=X509::Info, ev=X509::log_x509, path=x509]))
 0.000000   MetaHookPre   CallFunction(Log::create_stream, <frame>, (mysql::LOG, [columns=MySQL::Info, ev=MySQL::log_mysql, path=mysql]))
-0.000000   MetaHookPre   CallFunction(Log::write, <frame>, (PacketFilter::LOG, [ts=1580932537.132762, node=zeek, filter=ip or not ip, init=T, success=T]))
+0.000000   MetaHookPre   CallFunction(Log::write, <frame>, (PacketFilter::LOG, [ts=1584045167.489534, node=zeek, filter=ip or not ip, init=T, success=T]))
 0.000000   MetaHookPre   CallFunction(NetControl::check_plugins, <frame>, ())
 0.000000   MetaHookPre   CallFunction(NetControl::init, <null>, ())
 0.000000   MetaHookPre   CallFunction(Notice::want_pp, <frame>, ())
@@ -1439,6 +1451,10 @@
 0.000000   MetaHookPre   CallFunction(Option::set_change_handler, <frame>, (Weird::sampling_whitelist, Config::config_option_changed{ Config::log = (coerce [$ts=network_time(), $id=Config::ID, $old_value=Config::format_value(lookup_ID(Config::ID)), $new_value=Config::format_value(Config::new_value)] to Config::Info)if ( != Config::location) Config::log$location = Config::locationLog::write(Config::LOG, Config::log)return (Config::new_value)}, -100))
 0.000000   MetaHookPre   CallFunction(Option::set_change_handler, <frame>, (Weird::sampling_whitelist, Config::weird_option_change_sampling_whitelist{ if (Weird::sampling_whitelist == Config::ID) { Reporter::set_weird_sampling_whitelist(Config::new_value)}return (Config::new_value)}, 5))
 0.000000   MetaHookPre   CallFunction(Option::set_change_handler, <frame>, (Weird::weird_do_not_ignore_repeats, Config::config_option_changed{ Config::log = (coerce [$ts=network_time(), $id=Config::ID, $old_value=Config::format_value(lookup_ID(Config::ID)), $new_value=Config::format_value(Config::new_value)] to Config::Info)if ( != Config::location) Config::log$location = Config::locationLog::write(Config::LOG, Config::log)return (Config::new_value)}, -100))
+0.000000   MetaHookPre   CallFunction(Option::set_change_handler, <frame>, (X509::caching_required_encounters, Config::config_option_changed{ Config::log = (coerce [$ts=network_time(), $id=Config::ID, $old_value=Config::format_value(lookup_ID(Config::ID)), $new_value=Config::format_value(Config::new_value)] to Config::Info)if ( != Config::location) Config::log$location = Config::locationLog::write(Config::LOG, Config::log)return (Config::new_value)}, -100))
+0.000000   MetaHookPre   CallFunction(Option::set_change_handler, <frame>, (X509::caching_required_encounters_interval, Config::config_option_changed{ Config::log = (coerce [$ts=network_time(), $id=Config::ID, $old_value=Config::format_value(lookup_ID(Config::ID)), $new_value=Config::format_value(Config::new_value)] to Config::Info)if ( != Config::location) Config::log$location = Config::locationLog::write(Config::LOG, Config::log)return (Config::new_value)}, -100))
+0.000000   MetaHookPre   CallFunction(Option::set_change_handler, <frame>, (X509::certificate_cache_max_entries, Config::config_option_changed{ Config::log = (coerce [$ts=network_time(), $id=Config::ID, $old_value=Config::format_value(lookup_ID(Config::ID)), $new_value=Config::format_value(Config::new_value)] to Config::Info)if ( != Config::location) Config::log$location = Config::locationLog::write(Config::LOG, Config::log)return (Config::new_value)}, -100))
+0.000000   MetaHookPre   CallFunction(Option::set_change_handler, <frame>, (X509::certificate_cache_minimum_eviction_interval, Config::config_option_changed{ Config::log = (coerce [$ts=network_time(), $id=Config::ID, $old_value=Config::format_value(lookup_ID(Config::ID)), $new_value=Config::format_value(Config::new_value)] to Config::Info)if ( != Config::location) Config::log$location = Config::locationLog::write(Config::LOG, Config::log)return (Config::new_value)}, -100))
 0.000000   MetaHookPre   CallFunction(Option::set_change_handler, <frame>, (default_file_bof_buffer_size, Config::config_option_changed{ Config::log = (coerce [$ts=network_time(), $id=Config::ID, $old_value=Config::format_value(lookup_ID(Config::ID)), $new_value=Config::format_value(Config::new_value)] to Config::Info)if ( != Config::location) Config::log$location = Config::locationLog::write(Config::LOG, Config::log)return (Config::new_value)}, -100))
 0.000000   MetaHookPre   CallFunction(Option::set_change_handler, <frame>, (default_file_timeout_interval, Config::config_option_changed{ Config::log = (coerce [$ts=network_time(), $id=Config::ID, $old_value=Config::format_value(lookup_ID(Config::ID)), $new_value=Config::format_value(Config::new_value)] to Config::Info)if ( != Config::location) Config::log$location = Config::locationLog::write(Config::LOG, Config::log)return (Config::new_value)}, -100))
 0.000000   MetaHookPre   CallFunction(PacketFilter::build, <frame>, ())
@@ -1471,6 +1487,8 @@
 0.000000   MetaHookPre   CallFunction(set_to_regex, <frame>, ({}, (^\.?|\.)(~~)$))
 0.000000   MetaHookPre   CallFunction(string_to_pattern, <frame>, ((^\.?|\.)()$, F))
 0.000000   MetaHookPre   CallFunction(sub, <frame>, ((^\.?|\.)(~~)$, <...>/, ))
+0.000000   MetaHookPre   CallFunction(x509_set_certificate_cache, <frame>, ({}))
+0.000000   MetaHookPre   CallFunction(x509_set_certificate_cache_hit_callback, <frame>, (X509::x509_certificate_cache_replay{ <init> X509::i{ if (X509::f$info?$x509) return event x509_certificate(X509::f, X509::e$handle, X509::e$certificate)for ([X509::i] in X509::e$extensions_cache) { X509::ext = X509::e$extensions_cache[X509::i]if (X509::ext is X509::Extension) event x509_extension(X509::f, (X509::ext as X509::Extension))elseif (X509::ext is X509::BasicConstraints) event x509_ext_basic_constraints(X509::f, (X509::ext as X509::BasicConstraints))elseif (X509::ext is X509::SubjectAlternativeName) event x509_ext_subject_alternative_name(X509::f, (X509::ext as X509::SubjectAlternativeName))elseif (X509::ext is X509::SctInfo) { X509::s = (X509::ext as X509::SctInfo)event x509_ocsp_ext_signed_certificate_timestamp(X509::f, X509::s$version, X509::s$logid, X509::s$timestamp, X509::s$hash_alg, X509::s$sig_alg, X509::s$signature)}elseReporter::error(fmt(Encountered unknown extension while replaying certificate with fuid %s, X509::f$id))}}}))
 0.000000   MetaHookPre   CallFunction(zeek_init, <null>, ())
 0.000000   MetaHookPre   DrainEvents()
 0.000000   MetaHookPre   LoadFile(0, ..<...>/main.zeek)
@@ -1980,6 +1998,9 @@
 0.000000 | HookCallFunction Files::register_for_mime_type(Files::ANALYZER_SHA1, application/pkix-cert)
 0.000000 | HookCallFunction Files::register_for_mime_type(Files::ANALYZER_SHA1, application/x-x509-ca-cert)
 0.000000 | HookCallFunction Files::register_for_mime_type(Files::ANALYZER_SHA1, application/x-x509-user-cert)
+0.000000 | HookCallFunction Files::register_for_mime_type(Files::ANALYZER_SHA256, application/pkix-cert)
+0.000000 | HookCallFunction Files::register_for_mime_type(Files::ANALYZER_SHA256, application/x-x509-ca-cert)
+0.000000 | HookCallFunction Files::register_for_mime_type(Files::ANALYZER_SHA256, application/x-x509-user-cert)
 0.000000 | HookCallFunction Files::register_for_mime_type(Files::ANALYZER_X509, application/pkix-cert)
 0.000000 | HookCallFunction Files::register_for_mime_type(Files::ANALYZER_X509, application/x-x509-ca-cert)
 0.000000 | HookCallFunction Files::register_for_mime_type(Files::ANALYZER_X509, application/x-x509-user-cert)
@@ -2083,7 +2104,7 @@
 0.000000 | HookCallFunction Log::__create_stream(Weird::LOG, [columns=Weird::Info, ev=Weird::log_weird, path=weird])
 0.000000 | HookCallFunction Log::__create_stream(X509::LOG, [columns=X509::Info, ev=X509::log_x509, path=x509])
 0.000000 | HookCallFunction Log::__create_stream(mysql::LOG, [columns=MySQL::Info, ev=MySQL::log_mysql, path=mysql])
-0.000000 | HookCallFunction Log::__write(PacketFilter::LOG, [ts=1580932537.132762, node=zeek, filter=ip or not ip, init=T, success=T])
+0.000000 | HookCallFunction Log::__write(PacketFilter::LOG, [ts=1584045167.489534, node=zeek, filter=ip or not ip, init=T, success=T])
 0.000000 | HookCallFunction Log::add_default_filter(Broker::LOG)
 0.000000 | HookCallFunction Log::add_default_filter(Cluster::LOG)
 0.000000 | HookCallFunction Log::add_default_filter(Config::LOG)
@@ -2264,7 +2285,7 @@
 0.000000 | HookCallFunction Log::create_stream(Weird::LOG, [columns=Weird::Info, ev=Weird::log_weird, path=weird])
 0.000000 | HookCallFunction Log::create_stream(X509::LOG, [columns=X509::Info, ev=X509::log_x509, path=x509])
 0.000000 | HookCallFunction Log::create_stream(mysql::LOG, [columns=MySQL::Info, ev=MySQL::log_mysql, path=mysql])
-0.000000 | HookCallFunction Log::write(PacketFilter::LOG, [ts=1580932537.132762, node=zeek, filter=ip or not ip, init=T, success=T])
+0.000000 | HookCallFunction Log::write(PacketFilter::LOG, [ts=1584045167.489534, node=zeek, filter=ip or not ip, init=T, success=T])
 0.000000 | HookCallFunction NetControl::check_plugins()
 0.000000 | HookCallFunction NetControl::init()
 0.000000 | HookCallFunction Notice::want_pp()
@@ -2342,6 +2363,10 @@
 0.000000 | HookCallFunction Option::set_change_handler(Weird::sampling_whitelist, Config::config_option_changed{ Config::log = (coerce [$ts=network_time(), $id=Config::ID, $old_value=Config::format_value(lookup_ID(Config::ID)), $new_value=Config::format_value(Config::new_value)] to Config::Info)if ( != Config::location) Config::log$location = Config::locationLog::write(Config::LOG, Config::log)return (Config::new_value)}, -100)
 0.000000 | HookCallFunction Option::set_change_handler(Weird::sampling_whitelist, Config::weird_option_change_sampling_whitelist{ if (Weird::sampling_whitelist == Config::ID) { Reporter::set_weird_sampling_whitelist(Config::new_value)}return (Config::new_value)}, 5)
 0.000000 | HookCallFunction Option::set_change_handler(Weird::weird_do_not_ignore_repeats, Config::config_option_changed{ Config::log = (coerce [$ts=network_time(), $id=Config::ID, $old_value=Config::format_value(lookup_ID(Config::ID)), $new_value=Config::format_value(Config::new_value)] to Config::Info)if ( != Config::location) Config::log$location = Config::locationLog::write(Config::LOG, Config::log)return (Config::new_value)}, -100)
+0.000000 | HookCallFunction Option::set_change_handler(X509::caching_required_encounters, Config::config_option_changed{ Config::log = (coerce [$ts=network_time(), $id=Config::ID, $old_value=Config::format_value(lookup_ID(Config::ID)), $new_value=Config::format_value(Config::new_value)] to Config::Info)if ( != Config::location) Config::log$location = Config::locationLog::write(Config::LOG, Config::log)return (Config::new_value)}, -100)
+0.000000 | HookCallFunction Option::set_change_handler(X509::caching_required_encounters_interval, Config::config_option_changed{ Config::log = (coerce [$ts=network_time(), $id=Config::ID, $old_value=Config::format_value(lookup_ID(Config::ID)), $new_value=Config::format_value(Config::new_value)] to Config::Info)if ( != Config::location) Config::log$location = Config::locationLog::write(Config::LOG, Config::log)return (Config::new_value)}, -100)
+0.000000 | HookCallFunction Option::set_change_handler(X509::certificate_cache_max_entries, Config::config_option_changed{ Config::log = (coerce [$ts=network_time(), $id=Config::ID, $old_value=Config::format_value(lookup_ID(Config::ID)), $new_value=Config::format_value(Config::new_value)] to Config::Info)if ( != Config::location) Config::log$location = Config::locationLog::write(Config::LOG, Config::log)return (Config::new_value)}, -100)
+0.000000 | HookCallFunction Option::set_change_handler(X509::certificate_cache_minimum_eviction_interval, Config::config_option_changed{ Config::log = (coerce [$ts=network_time(), $id=Config::ID, $old_value=Config::format_value(lookup_ID(Config::ID)), $new_value=Config::format_value(Config::new_value)] to Config::Info)if ( != Config::location) Config::log$location = Config::locationLog::write(Config::LOG, Config::log)return (Config::new_value)}, -100)
 0.000000 | HookCallFunction Option::set_change_handler(default_file_bof_buffer_size, Config::config_option_changed{ Config::log = (coerce [$ts=network_time(), $id=Config::ID, $old_value=Config::format_value(lookup_ID(Config::ID)), $new_value=Config::format_value(Config::new_value)] to Config::Info)if ( != Config::location) Config::log$location = Config::locationLog::write(Config::LOG, Config::log)return (Config::new_value)}, -100)
 0.000000 | HookCallFunction Option::set_change_handler(default_file_timeout_interval, Config::config_option_changed{ Config::log = (coerce [$ts=network_time(), $id=Config::ID, $old_value=Config::format_value(lookup_ID(Config::ID)), $new_value=Config::format_value(Config::new_value)] to Config::Info)if ( != Config::location) Config::log$location = Config::locationLog::write(Config::LOG, Config::log)return (Config::new_value)}, -100)
 0.000000 | HookCallFunction PacketFilter::build()
@@ -2374,6 +2399,8 @@
 0.000000 | HookCallFunction set_to_regex({}, (^\.?|\.)(~~)$)
 0.000000 | HookCallFunction string_to_pattern((^\.?|\.)()$, F)
 0.000000 | HookCallFunction sub((^\.?|\.)(~~)$, <...>/, )
+0.000000 | HookCallFunction x509_set_certificate_cache({})
+0.000000 | HookCallFunction x509_set_certificate_cache_hit_callback(X509::x509_certificate_cache_replay{ <init> X509::i{ if (X509::f$info?$x509) return event x509_certificate(X509::f, X509::e$handle, X509::e$certificate)for ([X509::i] in X509::e$extensions_cache) { X509::ext = X509::e$extensions_cache[X509::i]if (X509::ext is X509::Extension) event x509_extension(X509::f, (X509::ext as X509::Extension))elseif (X509::ext is X509::BasicConstraints) event x509_ext_basic_constraints(X509::f, (X509::ext as X509::BasicConstraints))elseif (X509::ext is X509::SubjectAlternativeName) event x509_ext_subject_alternative_name(X509::f, (X509::ext as X509::SubjectAlternativeName))elseif (X509::ext is X509::SctInfo) { X509::s = (X509::ext as X509::SctInfo)event x509_ocsp_ext_signed_certificate_timestamp(X509::f, X509::s$version, X509::s$logid, X509::s$timestamp, X509::s$hash_alg, X509::s$sig_alg, X509::s$signature)}elseReporter::error(fmt(Encountered unknown extension while replaying certificate with fuid %s, X509::f$id))}}})
 0.000000 | HookCallFunction zeek_init()
 0.000000 | HookDrainEvents
 0.000000 | HookLoadFile  ..<...>/main.zeek
@@ -2705,7 +2732,7 @@
 0.000000 | HookLoadFile  base<...>/xmpp
 0.000000 | HookLoadFile  base<...>/zeek.bif.zeek
 0.000000 | HookLogInit   packet_filter 1/1 {ts (time), node (string), filter (string), init (bool), success (bool)}
-0.000000 | HookLogWrite  packet_filter [ts=1580932537.132762, node=zeek, filter=ip or not ip, init=T, success=T]
+0.000000 | HookLogWrite  packet_filter [ts=1584045167.489534, node=zeek, filter=ip or not ip, init=T, success=T]
 0.000000 | HookQueueEvent NetControl::init()
 0.000000 | HookQueueEvent filter_change_tracking()
 0.000000 | HookQueueEvent zeek_init()

testing/btest/Baseline/scripts.base.files.x509.caching-hook/.stdout

@@ -0,0 +1,3 @@
+Encountered cached certificate not further handled by core, 6bacfa4536150ed996f2b0c05ab6e345a257225f449aeb9d2018ccd88f4ede43
+Encountered cached certificate not further handled by core, a047a37fa2d2e118a4f5095fe074d6cfe0e352425a7632bf8659c03919a6c81d
+Encountered cached certificate not further handled by core, 3c35cc963eb004451323d3275d05b353235053490d9cd83729a2faf5e7ca1cc0

testing/btest/Baseline/scripts.base.files.x509.caching-hook/x509.log

@@ -0,0 +1,12 @@
+#separator \x09
+#set_separator	,
+#empty_field	(empty)
+#unset_field	-
+#path	x509
+#open	2020-03-11-20-12-31
+#fields	ts	id	certificate.version	certificate.serial	certificate.subject	certificate.issuer	certificate.not_valid_before	certificate.not_valid_after	certificate.key_alg	certificate.sig_alg	certificate.key_type	certificate.key_length	certificate.exponent	certificate.curve	san.dns	san.uri	san.email	san.ip	basic_constraints.ca	basic_constraints.path_len
+#types	time	string	count	string	string	string	time	time	string	string	string	count	string	string	vector[string]	vector[string]	vector[string]	vector[addr]	bool	count
+1394747126.862409	FlaIzV19yTmBYwWwc6	3	4A2C8628C1010633	CN=*.google.com,O=Google Inc,L=Mountain View,ST=California,C=US	CN=Google Internet Authority G2,O=Google Inc,C=US	1393341558.000000	1401062400.000000	rsaEncryption	sha1WithRSAEncryption	rsa	2048	65537	-	*.google.com,*.android.com,*.appengine.google.com,*.cloud.google.com,*.google-analytics.com,*.google.ca,*.google.cl,*.google.co.in,*.google.co.jp,*.google.co.uk,*.google.com.ar,*.google.com.au,*.google.com.br,*.google.com.co,*.google.com.mx,*.google.com.tr,*.google.com.vn,*.google.de,*.google.es,*.google.fr,*.google.hu,*.google.it,*.google.nl,*.google.pl,*.google.pt,*.googleapis.cn,*.googlecommerce.com,*.googlevideo.com,*.gstatic.com,*.gvt1.com,*.urchin.com,*.url.google.com,*.youtube-nocookie.com,*.youtube.com,*.youtubeeducation.com,*.ytimg.com,android.com,g.co,goo.gl,google-analytics.com,google.com,googlecommerce.com,urchin.com,youtu.be,youtube.com,youtubeeducation.com	-	-	-	F	-
+1394747126.862409	F0BeiV3cMsGkNML0P2	3	023A69	CN=Google Internet Authority G2,O=Google Inc,C=US	CN=GeoTrust Global CA,O=GeoTrust Inc.,C=US	1365174955.000000	1428160555.000000	rsaEncryption	sha1WithRSAEncryption	rsa	2048	65537	-	-	-	-	-	T	0
+1394747126.862409	F6PfYi2WUoPdIJrhpg	3	12BBE6	CN=GeoTrust Global CA,O=GeoTrust Inc.,C=US	OU=Equifax Secure Certificate Authority,O=Equifax,C=US	1021953600.000000	1534824000.000000	rsaEncryption	sha1WithRSAEncryption	rsa	2048	65537	-	-	-	-	-	T	-
+#close	2020-03-11-20-12-32

testing/btest/Baseline/scripts.base.files.x509.caching/.stdout

@@ -0,0 +1,3 @@
+Encountered cached certificate not further handled by core, 6bacfa4536150ed996f2b0c05ab6e345a257225f449aeb9d2018ccd88f4ede43
+Encountered cached certificate not further handled by core, a047a37fa2d2e118a4f5095fe074d6cfe0e352425a7632bf8659c03919a6c81d
+Encountered cached certificate not further handled by core, 3c35cc963eb004451323d3275d05b353235053490d9cd83729a2faf5e7ca1cc0

testing/btest/Baseline/scripts.base.files.x509.caching/x509.log

@@ -0,0 +1,15 @@
+#separator \x09
+#set_separator	,
+#empty_field	(empty)
+#unset_field	-
+#path	x509
+#open	2020-03-11-20-10-30
+#fields	ts	id	certificate.version	certificate.serial	certificate.subject	certificate.issuer	certificate.not_valid_before	certificate.not_valid_after	certificate.key_alg	certificate.sig_alg	certificate.key_type	certificate.key_length	certificate.exponent	certificate.curve	san.dns	san.uri	san.email	san.ip	basic_constraints.ca	basic_constraints.path_len
+#types	time	string	count	string	string	string	time	time	string	string	string	count	string	string	vector[string]	vector[string]	vector[string]	vector[addr]	bool	count
+1394747126.862409	FlaIzV19yTmBYwWwc6	3	4A2C8628C1010633	CN=*.google.com,O=Google Inc,L=Mountain View,ST=California,C=US	CN=Google Internet Authority G2,O=Google Inc,C=US	1393341558.000000	1401062400.000000	rsaEncryption	sha1WithRSAEncryption	rsa	2048	65537	-	*.google.com,*.android.com,*.appengine.google.com,*.cloud.google.com,*.google-analytics.com,*.google.ca,*.google.cl,*.google.co.in,*.google.co.jp,*.google.co.uk,*.google.com.ar,*.google.com.au,*.google.com.br,*.google.com.co,*.google.com.mx,*.google.com.tr,*.google.com.vn,*.google.de,*.google.es,*.google.fr,*.google.hu,*.google.it,*.google.nl,*.google.pl,*.google.pt,*.googleapis.cn,*.googlecommerce.com,*.googlevideo.com,*.gstatic.com,*.gvt1.com,*.urchin.com,*.url.google.com,*.youtube-nocookie.com,*.youtube.com,*.youtubeeducation.com,*.ytimg.com,android.com,g.co,goo.gl,google-analytics.com,google.com,googlecommerce.com,urchin.com,youtu.be,youtube.com,youtubeeducation.com	-	-	-	F	-
+1394747126.862409	F0BeiV3cMsGkNML0P2	3	023A69	CN=Google Internet Authority G2,O=Google Inc,C=US	CN=GeoTrust Global CA,O=GeoTrust Inc.,C=US	1365174955.000000	1428160555.000000	rsaEncryption	sha1WithRSAEncryption	rsa	2048	65537	-	-	-	-	-	T	0
+1394747126.862409	F6PfYi2WUoPdIJrhpg	3	12BBE6	CN=GeoTrust Global CA,O=GeoTrust Inc.,C=US	OU=Equifax Secure Certificate Authority,O=Equifax,C=US	1021953600.000000	1534824000.000000	rsaEncryption	sha1WithRSAEncryption	rsa	2048	65537	-	-	-	-	-	T	-
+1394747129.512954	FOye6a4kt8a7QChqw3	3	4A2C8628C1010633	CN=*.google.com,O=Google Inc,L=Mountain View,ST=California,C=US	CN=Google Internet Authority G2,O=Google Inc,C=US	1393341558.000000	1401062400.000000	rsaEncryption	sha1WithRSAEncryption	rsa	2048	65537	-	*.google.com,*.android.com,*.appengine.google.com,*.cloud.google.com,*.google-analytics.com,*.google.ca,*.google.cl,*.google.co.in,*.google.co.jp,*.google.co.uk,*.google.com.ar,*.google.com.au,*.google.com.br,*.google.com.co,*.google.com.mx,*.google.com.tr,*.google.com.vn,*.google.de,*.google.es,*.google.fr,*.google.hu,*.google.it,*.google.nl,*.google.pl,*.google.pt,*.googleapis.cn,*.googlecommerce.com,*.googlevideo.com,*.gstatic.com,*.gvt1.com,*.urchin.com,*.url.google.com,*.youtube-nocookie.com,*.youtube.com,*.youtubeeducation.com,*.ytimg.com,android.com,g.co,goo.gl,google-analytics.com,google.com,googlecommerce.com,urchin.com,youtu.be,youtube.com,youtubeeducation.com	-	-	-	F	-
+1394747129.512954	FytlLr3jOQenFAVtYi	3	023A69	CN=Google Internet Authority G2,O=Google Inc,C=US	CN=GeoTrust Global CA,O=GeoTrust Inc.,C=US	1365174955.000000	1428160555.000000	rsaEncryption	sha1WithRSAEncryption	rsa	2048	65537	-	-	-	-	-	T	0
+1394747129.512954	FEmnxy4DGbxkmtQJS1	3	12BBE6	CN=GeoTrust Global CA,O=GeoTrust Inc.,C=US	OU=Equifax Secure Certificate Authority,O=Equifax,C=US	1021953600.000000	1534824000.000000	rsaEncryption	sha1WithRSAEncryption	rsa	2048	65537	-	-	-	-	-	T	-
+#close	2020-03-11-20-10-30

testing/btest/Baseline/scripts.base.frameworks.file-analysis.smtp/out

@@ -65,6 +65,7 @@ application/x-x509-user-cert
 source: SSL
 MD5: 1bf9696d9f337805383427e88781d001
 SHA1: f5ccb1a724133607548b00d8eb402efca3076d58
+SHA256: f94f3f5bf51899148fa4c51a1b39bd98cd0bf053f2e838eb68a2a96d0359ed56
 FILE_NEW
 file #5, 0, 0
 FILE_OVER_NEW_CONNECTION
@@ -76,3 +77,4 @@ application/x-x509-ca-cert
 source: SSL
 MD5: 48f0e38385112eeca5fc9ffd402eaecd
 SHA1: 8e8321ca08b08e3726fe1d82996884eeb5f0d655
+SHA256: ac2b922ecfd5e01711772fea8ed372de9d1e2245fce3f57a9cdbec77296a424b

testing/btest/Baseline/scripts.policy.misc.dump-events/all-events-no-args.log

@@ -187,6 +187,7 @@
 1437831799.764576 file_over_new_connection
 1437831799.764576 file_sniff
 1437831799.764576 file_hash
+1437831799.764576 file_hash
 1437831799.764576 x509_certificate
 1437831799.764576 x509_extension
 1437831799.764576 x509_extension
@@ -205,6 +206,7 @@
 1437831799.764576 file_over_new_connection
 1437831799.764576 file_sniff
 1437831799.764576 file_hash
+1437831799.764576 file_hash
 1437831799.764576 x509_certificate
 1437831799.764576 x509_extension
 1437831799.764576 x509_extension

testing/btest/scripts/base/files/x509/caching-hook.test

@@ -0,0 +1,14 @@
+# Test that certificate caching works as expected.
+# Prevent certificate events to be raised/caching from occurring for cached certificates.
+
+# @TEST-EXEC: zeek -r $TRACES/tls/google-duplicate.trace %INPUT
+# @TEST-EXEC: btest-diff x509.log
+# @TEST-EXEC: btest-diff .stdout
+
+redef X509::caching_required_encounters = 1;
+
+hook X509::x509_certificate_cache_replay(f: fa_file, e: any, sha256: string) &priority=1
+	{
+	print "Encountered cached certificate not further handled by core", sha256;
+	break;
+	}

testing/btest/scripts/base/files/x509/caching.test

@@ -0,0 +1,12 @@
+# Test that certificate caching works as expected.
+
+# @TEST-EXEC: zeek -r $TRACES/tls/google-duplicate.trace %INPUT
+# @TEST-EXEC: btest-diff x509.log
+# @TEST-EXEC: btest-diff .stdout
+
+redef X509::caching_required_encounters = 1;
+
+hook X509::x509_certificate_cache_replay(f: fa_file, e: any, sha256: string) &priority=1
+	{
+	print "Encountered cached certificate not further handled by core", sha256;
+	}

testing/external/commit-hash.zeek-testing

@@ -1 +1 @@
-dd58cd3032f8f13af0c65500f18f07efd0cd09b2
+7034afc0cc7e6c216ef3d52fa0352b600dcca4e2

testing/external/commit-hash.zeek-testing-private

@@ -1 +1 @@
-6d348e86a9d6ec01fbf2c6971c71a771a3bf8341
+006f79ead969c3af9495d0e0c80c4343269893ec