common/util/logging.cc - third_party/verible - Git at Google

 // Copyright 2017-2020 The Verible Authors.
 //
 // Licensed under the Apache License, Version 2.0 (the "License");
 // you may not use this file except in compliance with the License.
 // You may obtain a copy of the License at
 //
 //      http://www.apache.org/licenses/LICENSE-2.0
 //
 // Unless required by applicable law or agreed to in writing, software
 // distributed under the License is distributed on an "AS IS" BASIS,
 // WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
 // See the License for the specific language governing permissions and
 // limitations under the License.

 #include "common/util/logging.h"

 // TODO(hzeller): avoid being dependent on absl internal
 #include <cstdlib>
 #include <cstring>
 #include <ctime>
 #include <string>
 #include <unordered_map>

 #include "absl/base/internal/cycleclock.h"
 #include "absl/base/internal/sysinfo.h"

 namespace verible {

 void VeribleAddLogSink(VeribleLogSink* sink) {
   // LogSink is not implemented.
   // If necessary, one can add the log sink support as follows.
   // 1. Define a global vector<VeribleLogSink> to keep track of all registered
   //    VeribleLogSink objects. Protect the global vector with mutex to make it
   //    thread-safe.
   // 2. Add/remove elements from the global vector<VeribleLogSink> in
   // VeribleAddLogSink
   //    and VeribleRemoveLogSink function
   // 3. Add logic in LogMessage::GenerateLogMessage() below to dispatch log
   //    messages to all the registered log sinks.
 }

 void VeribleRemoveLogSink(VeribleLogSink* sink) {
   // LogSink is not implemented.
 }

 namespace internal {
 namespace {

 int ParseInteger(const char* str, size_t size) {
   // Ideally we would use env_var / safe_strto64, but it is
   // hard to use here without pulling in a lot of dependencies,
   // so we use std:istringstream instead
   std::string integer_str(str, size);
   std::istringstream ss(integer_str);
   int level = 0;
   ss >> level;
   return level;
 }

 // Parse log level (int64_t) from environment variable (char*)
 int64_t LogLevelStrToInt(const char* tf_env_var_val) {
   if (tf_env_var_val == nullptr) {
     return 0;
   }
   return ParseInteger(tf_env_var_val, strlen(tf_env_var_val));
 }

 // Using StringPiece breaks Windows build.
 struct StringData {
   struct Hasher {
     size_t operator()(const StringData& sdata) const {
       // For dependency reasons, we cannot use hash.h here. Use DBJHash instead.
       size_t hash = 5381;
       const char* data = sdata.data;
       for (const char* top = data + sdata.size; data < top; ++data) {
         hash = ((hash << 5) + hash) + (*data);
       }
       return hash;
     }
   };

   StringData() = default;
   StringData(const char* data, size_t size) : data(data), size(size) {}

   bool operator==(const StringData& rhs) const {
     return size == rhs.size && memcmp(data, rhs.data, size) == 0;
   }

   const char* data = nullptr;
   size_t size = 0;
 };

 using VmoduleMap = std::unordered_map<StringData, int, StringData::Hasher>;

 // Returns a mapping from module name to VLOG level, derived from the
 // TF_CPP_VMODULE environment variable; ownership is transferred to the caller.
 VmoduleMap* VmodulesMapFromEnv() {
   // The value of the env var is supposed to be of the form:
   //    "foo=1,bar=2,baz=3"
   const char* env = getenv("TF_CPP_VMODULE");
   if (env == nullptr) {
     // If there is no TF_CPP_VMODULE configuration (most common case), return
     // nullptr so that the ShouldVlogModule() API can fast bail out of it.
     return nullptr;
   }
   // The memory returned by getenv() can be invalidated by following getenv() or
   // setenv() calls. And since we keep references to it in the VmoduleMap in
   // form of StringData objects, make a copy of it.
   const char* env_data = strdup(env);
   VmoduleMap* result = new VmoduleMap();
   while (true) {
     const char* eq = strchr(env_data, '=');
     if (eq == nullptr) {
       break;
     }
     const char* after_eq = eq + 1;

     // Comma either points at the next comma delimiter, or at a null terminator.
     // We check that the integer we parse ends at this delimiter.
     const char* comma = strchr(after_eq, ',');
     const char* new_env_data;
     if (comma == nullptr) {
       comma = strchr(after_eq, '\0');
       new_env_data = comma;
     } else {
       new_env_data = comma + 1;
     }
     (*result)[StringData(env_data, eq - env_data)] =
         ParseInteger(after_eq, comma - after_eq);
     env_data = new_env_data;
   }
   return result;
 }

 }  // namespace

 int64_t MinLogLevelFromEnv() {
   // We don't want to print logs during fuzzing as that would slow fuzzing down
   // by almost 2x. So, if we are in fuzzing mode (not just running a test), we
   // return a value so that nothing is actually printed. Since LOG uses >=
   // (see ~LogMessage in this file) to see if log messages need to be printed,
   // the value we're interested on to disable printing is the maximum severity.
   // See also http://llvm.org/docs/LibFuzzer.html#fuzzer-friendly-build-mode
 #ifdef FUZZING_BUILD_MODE_UNSAFE_FOR_PRODUCTION
   return verible::NUM_SEVERITIES;
 #else
   const char* tf_env_var_val = getenv("TF_CPP_MIN_LOG_LEVEL");
   return LogLevelStrToInt(tf_env_var_val);
 #endif
 }

 int64_t MinVLogLevelFromEnv() {
   // We don't want to print logs during fuzzing as that would slow fuzzing down
   // by almost 2x. So, if we are in fuzzing mode (not just running a test), we
   // return a value so that nothing is actually printed. Since VLOG uses <=
   // (see VLOG_IS_ON in logging.h) to see if log messages need to be printed,
   // the value we're interested on to disable printing is 0.
   // See also http://llvm.org/docs/LibFuzzer.html#fuzzer-friendly-build-mode
 #ifdef FUZZING_BUILD_MODE_UNSAFE_FOR_PRODUCTION
   return 0;
 #else
   const char* tf_env_var_val = getenv("TF_CPP_MIN_VLOG_LEVEL");
   return LogLevelStrToInt(tf_env_var_val);
 #endif
 }

 LogMessage::LogMessage(const char* fname, int line, int severity)
     : fname_(fname), line_(line), severity_(severity) {}

 LogMessage::~LogMessage() {
   // Read the min log level once during the first call to logging.
   static int64_t min_log_level = MinLogLevelFromEnv();
   if (severity_ >= min_log_level) {
     GenerateLogMessage();
   }
 }

 void LogMessage::GenerateLogMessage() {
   fprintf(stderr, "%c %s:%d] %s\n", "IWEF"[severity_], fname_, line_,
           str().c_str());
 }

 int64_t LogMessage::MinVLogLevel() {
   static int64_t min_vlog_level = MinVLogLevelFromEnv();
   return min_vlog_level;
 }

 bool LogMessage::VmoduleActivated(const char* fname, int level) {
   if (level <= MinVLogLevel()) {
     return true;
   }
   static VmoduleMap* vmodules = VmodulesMapFromEnv();
   if (ABSL_PREDICT_TRUE(vmodules == nullptr)) {
     return false;
   }
   const char* last_slash = strrchr(fname, '/');
   const char* module_start = last_slash == nullptr ? fname : last_slash + 1;
   const char* dot_after = strchr(module_start, '.');
   const char* module_limit =
       dot_after == nullptr ? strchr(fname, '\0') : dot_after;
   StringData module(module_start, module_limit - module_start);
   auto it = vmodules->find(module);
   return it != vmodules->end() && it->second >= level;
 }

 LogMessageFatal::LogMessageFatal(const char* file, int line)
     : LogMessage(file, line, FATAL) {}
 LogMessageFatal::~LogMessageFatal() {
   // abort() ensures we don't return (we promised we would not via
   // ATTRIBUTE_NORETURN).
   GenerateLogMessage();
   abort();
 }

 void LogString(const char* fname, int line, int severity,
                const std::string& message) {
   LogMessage(fname, line, severity) << message;
 }

 template <>
 void MakeCheckOpValueString(std::ostream* os, const char& v) {
   if (v >= 32 && v <= 126) {
     (*os) << "'" << v << "'";
   } else {
     (*os) << "char value " << static_cast<short>(v);
   }
 }

 template <>
 void MakeCheckOpValueString(std::ostream* os, const signed char& v) {
   if (v >= 32 && v <= 126) {
     (*os) << "'" << v << "'";
   } else {
     (*os) << "signed char value " << static_cast<short>(v);
   }
 }

 template <>
 void MakeCheckOpValueString(std::ostream* os, const unsigned char& v) {
   if (v >= 32 && v <= 126) {
     (*os) << "'" << v << "'";
   } else {
     (*os) << "unsigned char value " << static_cast<unsigned short>(v);
   }
 }

 template <>
 void MakeCheckOpValueString(std::ostream* os, const std::nullptr_t& p) {
   (*os) << "nullptr";
 }

 CheckOpMessageBuilder::CheckOpMessageBuilder(const char* exprtext)
     : stream_(new std::ostringstream) {
   *stream_ << "Check failed: " << exprtext << " (";
 }

 CheckOpMessageBuilder::~CheckOpMessageBuilder() { delete stream_; }

 std::ostream* CheckOpMessageBuilder::ForVar2() {
   *stream_ << " vs. ";
   return stream_;
 }

 std::string* CheckOpMessageBuilder::NewString() {
   *stream_ << ")";
   return new std::string(stream_->str());
 }

 namespace {
 // The following code behaves like AtomicStatsCounter::LossyAdd() for
 // speed since it is fine to lose occasional updates.
 // Returns old value of *counter.
 uint32_t LossyIncrement(std::atomic<uint32_t>* counter) {
   const uint32_t value = counter->load(std::memory_order_relaxed);
   counter->store(value + 1, std::memory_order_relaxed);
   return value;
 }
 }  // namespace

 bool LogEveryNState::ShouldLog(int n) {
   return n != 0 && (LossyIncrement(&counter_) % n) == 0;
 }

 bool LogFirstNState::ShouldLog(int n) {
   const uint32_t counter_value = counter_.load(std::memory_order_relaxed);
   if (counter_value < static_cast<uint32_t>(n)) {
     counter_.store(counter_value + 1, std::memory_order_relaxed);
     return true;
   }
   return false;
 }

 bool LogEveryPow2State::ShouldLog(int ignored) {
   const uint32_t new_value = LossyIncrement(&counter_) + 1;
   return (new_value & (new_value - 1)) == 0;
 }

 bool LogEveryNSecState::ShouldLog(double seconds) {
   LossyIncrement(&counter_);
   const int64_t now_cycles = absl::base_internal::CycleClock::Now();
   int64_t next_cycles = next_log_time_cycles_.load(std::memory_order_relaxed);
   do {
     if (now_cycles <= next_cycles) return false;
   } while (!next_log_time_cycles_.compare_exchange_weak(
       next_cycles,
       now_cycles + seconds * absl::base_internal::CycleClock::Frequency(),
       std::memory_order_relaxed, std::memory_order_relaxed));
   return true;
 }

 }  // namespace internal
 }  // namespace verible
	// Copyright 2017-2020 The Verible Authors.
	//
	// Licensed under the Apache License, Version 2.0 (the "License");
	// you may not use this file except in compliance with the License.
	// You may obtain a copy of the License at
	//
	// http://www.apache.org/licenses/LICENSE-2.0
	//
	// Unless required by applicable law or agreed to in writing, software
	// distributed under the License is distributed on an "AS IS" BASIS,
	// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
	// See the License for the specific language governing permissions and
	// limitations under the License.

	#include "common/util/logging.h"

	// TODO(hzeller): avoid being dependent on absl internal
	#include <cstdlib>
	#include <cstring>
	#include <ctime>
	#include <string>
	#include <unordered_map>

	#include "absl/base/internal/cycleclock.h"
	#include "absl/base/internal/sysinfo.h"

	namespace verible {

	void VeribleAddLogSink(VeribleLogSink* sink) {
	// LogSink is not implemented.
	// If necessary, one can add the log sink support as follows.
	// 1. Define a global vector<VeribleLogSink> to keep track of all registered
	// VeribleLogSink objects. Protect the global vector with mutex to make it
	// thread-safe.
	// 2. Add/remove elements from the global vector<VeribleLogSink> in
	// VeribleAddLogSink
	// and VeribleRemoveLogSink function
	// 3. Add logic in LogMessage::GenerateLogMessage() below to dispatch log
	// messages to all the registered log sinks.
	}

	void VeribleRemoveLogSink(VeribleLogSink* sink) {
	// LogSink is not implemented.
	}

	namespace internal {
	namespace {

	int ParseInteger(const char* str, size_t size) {
	// Ideally we would use env_var / safe_strto64, but it is
	// hard to use here without pulling in a lot of dependencies,
	// so we use std:istringstream instead
	std::string integer_str(str, size);
	std::istringstream ss(integer_str);
	int level = 0;
	ss >> level;
	return level;
	}

	// Parse log level (int64_t) from environment variable (char*)
	int64_t LogLevelStrToInt(const char* tf_env_var_val) {
	if (tf_env_var_val == nullptr) {
	return 0;
	}
	return ParseInteger(tf_env_var_val, strlen(tf_env_var_val));
	}

	// Using StringPiece breaks Windows build.
	struct StringData {
	struct Hasher {
	size_t operator()(const StringData& sdata) const {
	// For dependency reasons, we cannot use hash.h here. Use DBJHash instead.
	size_t hash = 5381;
	const char* data = sdata.data;
	for (const char* top = data + sdata.size; data < top; ++data) {
	hash = ((hash << 5) + hash) + (*data);
	}
	return hash;
	}
	};

	StringData() = default;
	StringData(const char* data, size_t size) : data(data), size(size) {}

	bool operator==(const StringData& rhs) const {
	return size == rhs.size && memcmp(data, rhs.data, size) == 0;
	}

	const char* data = nullptr;
	size_t size = 0;
	};

	using VmoduleMap = std::unordered_map<StringData, int, StringData::Hasher>;

	// Returns a mapping from module name to VLOG level, derived from the
	// TF_CPP_VMODULE environment variable; ownership is transferred to the caller.
	VmoduleMap* VmodulesMapFromEnv() {
	// The value of the env var is supposed to be of the form:
	// "foo=1,bar=2,baz=3"
	const char* env = getenv("TF_CPP_VMODULE");
	if (env == nullptr) {
	// If there is no TF_CPP_VMODULE configuration (most common case), return
	// nullptr so that the ShouldVlogModule() API can fast bail out of it.
	return nullptr;
	}
	// The memory returned by getenv() can be invalidated by following getenv() or
	// setenv() calls. And since we keep references to it in the VmoduleMap in
	// form of StringData objects, make a copy of it.
	const char* env_data = strdup(env);
	VmoduleMap* result = new VmoduleMap();
	while (true) {
	const char* eq = strchr(env_data, '=');
	if (eq == nullptr) {
	break;
	}
	const char* after_eq = eq + 1;

	// Comma either points at the next comma delimiter, or at a null terminator.
	// We check that the integer we parse ends at this delimiter.
	const char* comma = strchr(after_eq, ',');
	const char* new_env_data;
	if (comma == nullptr) {
	comma = strchr(after_eq, '\0');
	new_env_data = comma;
	} else {
	new_env_data = comma + 1;
	}
	(*result)[StringData(env_data, eq - env_data)] =
	ParseInteger(after_eq, comma - after_eq);
	env_data = new_env_data;
	}
	return result;
	}

	} // namespace

	int64_t MinLogLevelFromEnv() {
	// We don't want to print logs during fuzzing as that would slow fuzzing down
	// by almost 2x. So, if we are in fuzzing mode (not just running a test), we
	// return a value so that nothing is actually printed. Since LOG uses >=
	// (see ~LogMessage in this file) to see if log messages need to be printed,
	// the value we're interested on to disable printing is the maximum severity.
	// See also http://llvm.org/docs/LibFuzzer.html#fuzzer-friendly-build-mode
	#ifdef FUZZING_BUILD_MODE_UNSAFE_FOR_PRODUCTION
	return verible::NUM_SEVERITIES;
	#else
	const char* tf_env_var_val = getenv("TF_CPP_MIN_LOG_LEVEL");
	return LogLevelStrToInt(tf_env_var_val);
	#endif
	}

	int64_t MinVLogLevelFromEnv() {
	// We don't want to print logs during fuzzing as that would slow fuzzing down
	// by almost 2x. So, if we are in fuzzing mode (not just running a test), we
	// return a value so that nothing is actually printed. Since VLOG uses <=
	// (see VLOG_IS_ON in logging.h) to see if log messages need to be printed,
	// the value we're interested on to disable printing is 0.
	// See also http://llvm.org/docs/LibFuzzer.html#fuzzer-friendly-build-mode
	#ifdef FUZZING_BUILD_MODE_UNSAFE_FOR_PRODUCTION
	return 0;
	#else
	const char* tf_env_var_val = getenv("TF_CPP_MIN_VLOG_LEVEL");
	return LogLevelStrToInt(tf_env_var_val);
	#endif
	}

	LogMessage::LogMessage(const char* fname, int line, int severity)
	: fname_(fname), line_(line), severity_(severity) {}

	LogMessage::~LogMessage() {
	// Read the min log level once during the first call to logging.
	static int64_t min_log_level = MinLogLevelFromEnv();
	if (severity_ >= min_log_level) {
	GenerateLogMessage();
	}
	}

	void LogMessage::GenerateLogMessage() {
	fprintf(stderr, "%c %s:%d] %s\n", "IWEF"[severity_], fname_, line_,
	str().c_str());
	}

	int64_t LogMessage::MinVLogLevel() {
	static int64_t min_vlog_level = MinVLogLevelFromEnv();
	return min_vlog_level;
	}

	bool LogMessage::VmoduleActivated(const char* fname, int level) {
	if (level <= MinVLogLevel()) {
	return true;
	}
	static VmoduleMap* vmodules = VmodulesMapFromEnv();
	if (ABSL_PREDICT_TRUE(vmodules == nullptr)) {
	return false;
	}
	const char* last_slash = strrchr(fname, '/');
	const char* module_start = last_slash == nullptr ? fname : last_slash + 1;
	const char* dot_after = strchr(module_start, '.');
	const char* module_limit =
	dot_after == nullptr ? strchr(fname, '\0') : dot_after;
	StringData module(module_start, module_limit - module_start);
	auto it = vmodules->find(module);
	return it != vmodules->end() && it->second >= level;
	}

	LogMessageFatal::LogMessageFatal(const char* file, int line)
	: LogMessage(file, line, FATAL) {}
	LogMessageFatal::~LogMessageFatal() {
	// abort() ensures we don't return (we promised we would not via
	// ATTRIBUTE_NORETURN).
	GenerateLogMessage();
	abort();
	}

	void LogString(const char* fname, int line, int severity,
	const std::string& message) {
	LogMessage(fname, line, severity) << message;
	}

	template <>
	void MakeCheckOpValueString(std::ostream* os, const char& v) {
	if (v >= 32 && v <= 126) {
	(*os) << "'" << v << "'";
	} else {
	(*os) << "char value " << static_cast<short>(v);
	}
	}

	template <>
	void MakeCheckOpValueString(std::ostream* os, const signed char& v) {
	if (v >= 32 && v <= 126) {
	(*os) << "'" << v << "'";
	} else {
	(*os) << "signed char value " << static_cast<short>(v);
	}
	}

	template <>
	void MakeCheckOpValueString(std::ostream* os, const unsigned char& v) {
	if (v >= 32 && v <= 126) {
	(*os) << "'" << v << "'";
	} else {
	(*os) << "unsigned char value " << static_cast<unsigned short>(v);
	}
	}

	template <>
	void MakeCheckOpValueString(std::ostream* os, const std::nullptr_t& p) {
	(*os) << "nullptr";
	}

	CheckOpMessageBuilder::CheckOpMessageBuilder(const char* exprtext)
	: stream_(new std::ostringstream) {
	*stream_ << "Check failed: " << exprtext << " (";
	}

	CheckOpMessageBuilder::~CheckOpMessageBuilder() { delete stream_; }

	std::ostream* CheckOpMessageBuilder::ForVar2() {
	*stream_ << " vs. ";
	return stream_;
	}

	std::string* CheckOpMessageBuilder::NewString() {
	*stream_ << ")";
	return new std::string(stream_->str());
	}

	namespace {
	// The following code behaves like AtomicStatsCounter::LossyAdd() for
	// speed since it is fine to lose occasional updates.
	// Returns old value of *counter.
	uint32_t LossyIncrement(std::atomic<uint32_t>* counter) {
	const uint32_t value = counter->load(std::memory_order_relaxed);
	counter->store(value + 1, std::memory_order_relaxed);
	return value;
	}
	} // namespace

	bool LogEveryNState::ShouldLog(int n) {
	return n != 0 && (LossyIncrement(&counter_) % n) == 0;
	}

	bool LogFirstNState::ShouldLog(int n) {
	const uint32_t counter_value = counter_.load(std::memory_order_relaxed);
	if (counter_value < static_cast<uint32_t>(n)) {
	counter_.store(counter_value + 1, std::memory_order_relaxed);
	return true;
	}
	return false;
	}

	bool LogEveryPow2State::ShouldLog(int ignored) {
	const uint32_t new_value = LossyIncrement(&counter_) + 1;
	return (new_value & (new_value - 1)) == 0;
	}

	bool LogEveryNSecState::ShouldLog(double seconds) {
	LossyIncrement(&counter_);
	const int64_t now_cycles = absl::base_internal::CycleClock::Now();
	int64_t next_cycles = next_log_time_cycles_.load(std::memory_order_relaxed);
	do {
	if (now_cycles <= next_cycles) return false;
	} while (!next_log_time_cycles_.compare_exchange_weak(
	next_cycles,
	now_cycles + seconds * absl::base_internal::CycleClock::Frequency(),
	std::memory_order_relaxed, std::memory_order_relaxed));
	return true;
	}

	} // namespace internal
	} // namespace verible