]> git.sesse.net Git - casparcg/blobdiff - common/log.cpp
Fix a few Clang warnings.
[casparcg] / common / log.cpp
index 6704ef0994632a214ca08f1f814e60153f8db18f..63641a4efeaed8674b5634a3939b07b26bbd77df 100644 (file)
-/*\r
-* Copyright (c) 2011 Sveriges Television AB <info@casparcg.com>\r
-*\r
-* This file is part of CasparCG (www.casparcg.com).\r
-*\r
-* CasparCG is free software: you can redistribute it and/or modify\r
-* it under the terms of the GNU General Public License as published by\r
-* the Free Software Foundation, either version 3 of the License, or\r
-* (at your option) any later version.\r
-*\r
-* CasparCG is distributed in the hope that it will be useful,\r
-* but WITHOUT ANY WARRANTY; without even the implied warranty of\r
-* MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the\r
-* GNU General Public License for more details.\r
-*\r
-* You should have received a copy of the GNU General Public License\r
-* along with CasparCG. If not, see <http://www.gnu.org/licenses/>.\r
-*\r
-* Author: Robert Nagy, ronag89@gmail.com\r
-*/\r
-\r
-#include "stdafx.h"\r
-\r
-#if defined(_MSC_VER)\r
-#pragma warning (disable : 4100) // 'identifier' : unreferenced formal parameter\r
-#pragma warning (disable : 4512) // 'class' : assignment operator could not be generated\r
-#endif\r
-\r
-#include "log.h"\r
-\r
-#include "utf.h"\r
-\r
-#include "exception/exceptions.h"\r
-\r
-#include <ios>\r
-#include <string>\r
-#include <ostream>\r
-\r
-#include <boost/shared_ptr.hpp>\r
-#include <boost/make_shared.hpp>\r
-#include <boost/filesystem/convenience.hpp>\r
-#include <boost/date_time/posix_time/posix_time.hpp>\r
-#include <boost/algorithm/string.hpp>\r
-\r
-#include <boost/log/core/core.hpp>\r
-\r
-#include <boost/log/formatters/stream.hpp>\r
-#include <boost/log/formatters/attr.hpp>\r
-#include <boost/log/formatters/date_time.hpp>\r
-#include <boost/log/formatters/message.hpp>\r
-\r
-#include <boost/log/filters/attr.hpp>\r
-\r
-#include <boost/log/sinks/text_file_backend.hpp>\r
-\r
-#include <boost/log/detail/universal_path.hpp>\r
-\r
-#include <boost/log/sinks/text_file_backend.hpp>\r
-#include <boost/log/sinks/text_ostream_backend.hpp>\r
-#include <boost/log/sinks/sync_frontend.hpp>\r
-#include <boost/log/sinks/async_frontend.hpp>\r
-#include <boost/log/core/record.hpp>\r
-#include <boost/log/utility/attribute_value_extractor.hpp>\r
-\r
-#include <boost/log/utility/init/common_attributes.hpp>\r
-#include <boost/log/utility/empty_deleter.hpp>\r
-#include <boost/lambda/lambda.hpp>\r
-\r
-namespace caspar { namespace log {\r
-\r
-using namespace boost;\r
-\r
-void my_formatter(std::wostream& strm, boost::log::basic_record<wchar_t> const& rec)\r
-{\r
-    namespace lambda = boost::lambda;\r
-       \r
-       #pragma warning(disable : 4996)\r
-       time_t rawtime;\r
-       struct tm* timeinfo;\r
-       time(&rawtime );\r
-       timeinfo = localtime ( &rawtime );\r
-       char buffer [80];\r
-       strftime (buffer,80, "%c", timeinfo);\r
-       strm << L"[" << buffer << L"] ";\r
-               \r
-    boost::log::attributes::current_thread_id::held_type thread_id;\r
-    if(boost::log::extract<boost::log::attributes::current_thread_id::held_type>(L"ThreadID", rec.attribute_values(), lambda::var(thread_id) = lambda::_1))\r
-        strm << L"[" << thread_id << L"] ";\r
-\r
-\r
-    severity_level severity;\r
-    if(boost::log::extract<severity_level>(boost::log::sources::aux::severity_attribute_name<wchar_t>::get(), rec.attribute_values(), lambda::var(severity) = lambda::_1))\r
-       {\r
-               std::stringstream ss;\r
-               ss << severity;\r
-        strm << L"[" << severity << L"] ";\r
-               for(int n = 0; n < 7-static_cast<int>(ss.str().size()); ++n)\r
-                       strm << L" ";\r
-       }\r
-\r
-    strm << rec.message();\r
-}\r
-\r
-namespace internal{\r
-       \r
-void init()\r
-{      \r
-       boost::log::add_common_attributes<wchar_t>();\r
-       typedef boost::log::aux::add_common_attributes_constants<wchar_t> traits_t;\r
-\r
-       typedef boost::log::sinks::synchronous_sink<boost::log::sinks::wtext_file_backend> file_sink_type;\r
-\r
-       typedef boost::log::sinks::asynchronous_sink<boost::log::sinks::wtext_ostream_backend> stream_sink_type;\r
-\r
-       auto stream_backend = boost::make_shared<boost::log::sinks::wtext_ostream_backend>();\r
-       stream_backend->add_stream(boost::shared_ptr<std::wostream>(&std::wcout, boost::log::empty_deleter()));\r
-       stream_backend->auto_flush(true);\r
-\r
-       auto stream_sink = boost::make_shared<stream_sink_type>(stream_backend);\r
-       \r
-//#ifdef NDEBUG\r
-//     stream_sink->set_filter(boost::log::filters::attr<severity_level>(boost::log::sources::aux::severity_attribute_name<wchar_t>::get()) >= debug);\r
-//#else\r
-//     stream_sink->set_filter(boost::log::filters::attr<severity_level>(boost::log::sources::aux::severity_attribute_name<wchar_t>::get()) >= debug);\r
-//#endif\r
-\r
-       stream_sink->locked_backend()->set_formatter(&my_formatter);\r
-\r
-       boost::log::wcore::get()->add_sink(stream_sink);\r
-}\r
-\r
-}\r
-\r
-void add_file_sink(const std::wstring& folder)\r
-{      \r
-       boost::log::add_common_attributes<wchar_t>();\r
-       typedef boost::log::aux::add_common_attributes_constants<wchar_t> traits_t;\r
-\r
-       typedef boost::log::sinks::synchronous_sink<boost::log::sinks::wtext_file_backend> file_sink_type;\r
-\r
-       try\r
-       {\r
-               if(!boost::filesystem::is_directory(folder))\r
-                       BOOST_THROW_EXCEPTION(directory_not_found());\r
-\r
-               auto file_sink = boost::make_shared<file_sink_type>(\r
-                       boost::log::keywords::file_name = (folder + L"caspar_%Y-%m-%d.log"),\r
-                       boost::log::keywords::time_based_rotation = boost::log::sinks::file::rotation_at_time_point(0, 0, 0),\r
-                       boost::log::keywords::auto_flush = true,\r
-                       boost::log::keywords::open_mode = std::ios::app\r
-               );\r
-               \r
-               file_sink->locked_backend()->set_formatter(&my_formatter);\r
-\r
-//#ifdef NDEBUG\r
-//             file_sink->set_filter(boost::log::filters::attr<severity_level>(boost::log::sources::aux::severity_attribute_name<wchar_t>::get()) >= debug);\r
-//#else\r
-//             file_sink->set_filter(boost::log::filters::attr<severity_level>(boost::log::sources::aux::severity_attribute_name<wchar_t>::get()) >= debug);\r
-//#endif\r
-               boost::log::wcore::get()->add_sink(file_sink);\r
-       }\r
-       catch(...)\r
-       {\r
-               std::wcerr << L"Failed to Setup File Logging Sink" << std::endl << std::endl;\r
-       }\r
-}\r
-\r
-void set_log_level(const std::wstring& lvl)\r
-{      \r
-       if(boost::iequals(lvl, L"trace"))\r
-               boost::log::wcore::get()->set_filter(boost::log::filters::attr<severity_level>(boost::log::sources::aux::severity_attribute_name<wchar_t>::get()) >= trace);\r
-       else if(boost::iequals(lvl, L"debug"))\r
-               boost::log::wcore::get()->set_filter(boost::log::filters::attr<severity_level>(boost::log::sources::aux::severity_attribute_name<wchar_t>::get()) >= debug);\r
-       else if(boost::iequals(lvl, L"info"))\r
-               boost::log::wcore::get()->set_filter(boost::log::filters::attr<severity_level>(boost::log::sources::aux::severity_attribute_name<wchar_t>::get()) >= info);\r
-       else if(boost::iequals(lvl, L"warning"))\r
-               boost::log::wcore::get()->set_filter(boost::log::filters::attr<severity_level>(boost::log::sources::aux::severity_attribute_name<wchar_t>::get()) >= warning);\r
-       else if(boost::iequals(lvl, L"error"))\r
-               boost::log::wcore::get()->set_filter(boost::log::filters::attr<severity_level>(boost::log::sources::aux::severity_attribute_name<wchar_t>::get()) >= error);\r
-       else if(boost::iequals(lvl, L"fatal"))\r
-               boost::log::wcore::get()->set_filter(boost::log::filters::attr<severity_level>(boost::log::sources::aux::severity_attribute_name<wchar_t>::get()) >= fatal);\r
-}\r
-\r
-}}
\ No newline at end of file
+/*
+* Copyright (c) 2011 Sveriges Television AB <info@casparcg.com>
+*
+* This file is part of CasparCG (www.casparcg.com).
+*
+* CasparCG is free software: you can redistribute it and/or modify
+* it under the terms of the GNU General Public License as published by
+* the Free Software Foundation, either version 3 of the License, or
+* (at your option) any later version.
+*
+* CasparCG is distributed in the hope that it will be useful,
+* but WITHOUT ANY WARRANTY; without even the implied warranty of
+* MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+* GNU General Public License for more details.
+*
+* You should have received a copy of the GNU General Public License
+* along with CasparCG. If not, see <http://www.gnu.org/licenses/>.
+*
+* Author: Robert Nagy, ronag89@gmail.com
+*/
+
+#include "stdafx.h"
+
+#include "log.h"
+
+#include "os/threading.h"
+#include "except.h"
+#include "utf.h"
+
+#include <ios>
+#include <iomanip>
+#include <mutex>
+#include <string>
+#include <thread>
+#include <ostream>
+
+#include <boost/shared_ptr.hpp>
+#include <boost/make_shared.hpp>
+#include <boost/filesystem/convenience.hpp>
+#include <boost/date_time/posix_time/posix_time.hpp>
+#include <boost/algorithm/string.hpp>
+
+#include <boost/log/core.hpp>
+#include <boost/log/trivial.hpp>
+#include <boost/log/expressions.hpp>
+
+#include <boost/log/sinks/text_file_backend.hpp>
+#include <boost/log/sinks/text_ostream_backend.hpp>
+#include <boost/log/sinks/sync_frontend.hpp>
+#include <boost/log/sinks/async_frontend.hpp>
+#include <boost/log/core/record.hpp>
+#include <boost/log/attributes/attribute_value.hpp>
+#include <boost/log/attributes/function.hpp>
+#include <boost/log/utility/setup/common_attributes.hpp>
+
+#include <boost/core/null_deleter.hpp>
+#include <boost/lambda/lambda.hpp>
+#include <boost/bind.hpp>
+#include <boost/lexical_cast.hpp>
+#include <boost/property_tree/ptree.hpp>
+
+#include <tbb/atomic.h>
+
+namespace caspar { namespace log {
+
+using namespace boost;
+
+template<typename Stream>
+void append_timestamp(Stream& stream, boost::posix_time::ptime timestamp)
+{
+       auto date = timestamp.date();
+       auto time = timestamp.time_of_day();
+       auto milliseconds = time.fractional_seconds() / 1000; // microseconds to milliseconds
+
+       std::wstringstream buffer;
+
+       buffer
+               << std::setfill(L'0')
+               << L"["
+               << std::setw(4) << date.year() << L"-" << std::setw(2) << date.month().as_number() << "-" << std::setw(2) << date.day().as_number()
+               << L" "
+               << std::setw(2) << time.hours() << L":" << std::setw(2) << time.minutes() << L":" << std::setw(2) << time.seconds()
+               << L"."
+               << std::setw(3) << milliseconds
+               << L"] ";
+
+       stream << buffer.str();
+}
+
+class column_writer
+{
+       tbb::atomic<int> column_width_;
+public:
+       column_writer(int initial_width = 0)
+       {
+               column_width_ = initial_width;
+       }
+
+       template<typename Stream, typename Val>
+       void write(Stream& out, const Val& value)
+       {
+               std::wstring to_string = boost::lexical_cast<std::wstring>(value);
+               int length = static_cast<int>(to_string.size());
+               int read_width;
+
+               while ((read_width = column_width_) < length && column_width_.compare_and_swap(length, read_width) != read_width);
+               read_width = column_width_;
+
+               out << L"[" << to_string << L"] ";
+
+               for (int n = 0; n < read_width - length; ++n)
+                       out << L" ";
+       }
+};
+
+template<typename Stream>
+void my_formatter(bool print_all_characters, const boost::log::record_view& rec, Stream& strm)
+{
+       static column_writer thread_id_column;
+       static column_writer severity_column(7);
+       namespace expr = boost::log::expressions;
+
+       std::wstringstream pre_message_stream;
+       append_timestamp(pre_message_stream, boost::log::extract<boost::posix_time::ptime>("TimestampMillis", rec).get());
+       thread_id_column.write(pre_message_stream, boost::log::extract<std::int64_t>("NativeThreadId", rec));
+       severity_column.write(pre_message_stream, boost::log::extract<boost::log::trivial::severity_level>("Severity", rec));
+
+       auto pre_message = pre_message_stream.str();
+
+       strm << pre_message;
+
+       auto line_break_replacement = L"\n" + pre_message;
+
+       if (print_all_characters)
+       {
+               strm << boost::replace_all_copy(rec[expr::message].get<std::wstring>(), "\n", line_break_replacement);
+       }
+       else
+       {
+               strm << boost::replace_all_copy(replace_nonprintable_copy(rec[expr::message].get<std::wstring>(), L'?'), L"\n", line_break_replacement);
+       }
+}
+
+namespace internal{
+
+void init()
+{
+       boost::log::add_common_attributes();
+       boost::log::core::get()->add_global_attribute("NativeThreadId", boost::log::attributes::make_function(&get_current_thread_id));
+       boost::log::core::get()->add_global_attribute("TimestampMillis", boost::log::attributes::make_function([]
+       {
+               return boost::posix_time::microsec_clock::local_time();
+       }));
+       typedef boost::log::sinks::asynchronous_sink<boost::log::sinks::wtext_ostream_backend> stream_sink_type;
+
+       auto stream_backend = boost::make_shared<boost::log::sinks::wtext_ostream_backend>();
+       stream_backend->add_stream(boost::shared_ptr<std::wostream>(&std::wcout, boost::null_deleter()));
+       stream_backend->auto_flush(true);
+
+       auto stream_sink = boost::make_shared<stream_sink_type>(stream_backend);
+       // Never log calltrace to console. The terminal is too slow, so the log queue will build up faster than consumed.
+       stream_sink->set_filter(category != log_category::calltrace);
+
+       bool print_all_characters = false;
+       stream_sink->set_formatter(boost::bind(&my_formatter<boost::log::wformatting_ostream>, print_all_characters, _1, _2));
+
+       boost::log::core::get()->add_sink(stream_sink);
+}
+
+std::string current_exception_diagnostic_information()
+{
+       auto e = boost::current_exception_cast<const char*>();
+
+       if (e)
+               return std::string("[char *] = ") + *e + "\n";
+       else
+               return boost::current_exception_diagnostic_information();
+}
+
+}
+
+void add_file_sink(const std::wstring& file, const boost::log::filter& filter)
+{
+       typedef boost::log::sinks::synchronous_sink<boost::log::sinks::text_file_backend> file_sink_type;
+
+       try
+       {
+               if (!boost::filesystem::is_directory(boost::filesystem::path(file).parent_path()))
+                       CASPAR_THROW_EXCEPTION(directory_not_found());
+
+               auto file_sink = boost::make_shared<file_sink_type>(
+                       boost::log::keywords::file_name = (file + L"_%Y-%m-%d.log"),
+                       boost::log::keywords::time_based_rotation = boost::log::sinks::file::rotation_at_time_point(0, 0, 0),
+                       boost::log::keywords::auto_flush = true,
+                       boost::log::keywords::open_mode = std::ios::app
+                       );
+
+               bool print_all_characters = true;
+
+               file_sink->set_formatter(boost::bind(&my_formatter<boost::log::formatting_ostream>, print_all_characters, _1, _2));
+               file_sink->set_filter(filter);
+               boost::log::core::get()->add_sink(file_sink);
+       }
+       catch (...)
+       {
+               std::wcerr << L"Failed to Setup File Logging Sink" << std::endl << std::endl;
+       }
+}
+
+std::shared_ptr<void> add_preformatted_line_sink(std::function<void(std::string line)> formatted_line_sink)
+{
+       class sink_backend : public boost::log::sinks::basic_formatted_sink_backend<char>
+       {
+               std::function<void(std::string line)> formatted_line_sink_;
+       public:
+               // The dummy parameter is to work around a bug in newer Boost.Log, where single-argument
+               // constructor forwarders are not recognized unless the parameter uses Boost.Parameter.
+               sink_backend(std::function<void(std::string line)> formatted_line_sink, int)
+                       : formatted_line_sink_(std::move(formatted_line_sink))
+               {
+               }
+
+               void consume(const boost::log::record_view& rec, const std::string& formatted_message)
+               {
+                       try
+                       {
+                               formatted_line_sink_(formatted_message);
+                       }
+                       catch (...)
+                       {
+                               std::cerr << "[sink_backend] Error while consuming formatted message: " << formatted_message << std::endl << std::endl;
+                       }
+               }
+       };
+
+       typedef boost::log::sinks::synchronous_sink<sink_backend> sink_type;
+
+       auto sink = boost::make_shared<sink_type>(std::move(formatted_line_sink), 0);
+       bool print_all_characters = true;
+
+       sink->set_formatter(boost::bind(&my_formatter<boost::log::formatting_ostream>, print_all_characters, _1, _2));
+       sink->set_filter(category != log_category::calltrace);
+
+       boost::log::core::get()->add_sink(sink);
+
+       return std::shared_ptr<void>(nullptr, [=](void*)
+       {
+               boost::log::core::get()->remove_sink(sink);
+       });
+}
+
+std::mutex& get_filter_mutex()
+{
+       static std::mutex instance;
+
+       return instance;
+}
+
+boost::log::trivial::severity_level& get_level()
+{
+       static boost::log::trivial::severity_level instance;
+
+       return instance;
+}
+
+log_category& get_disabled_categories()
+{
+       static log_category instance = log_category::calltrace;
+
+       return instance;
+}
+
+void set_log_filter()
+{
+       auto severity_filter            = boost::log::trivial::severity >= get_level();
+       auto disabled_categories        = get_disabled_categories();
+
+       boost::log::core::get()->set_filter([=](const boost::log::attribute_value_set& attributes)
+       {
+               return severity_filter(attributes)
+                       && static_cast<int>(disabled_categories & attributes["Channel"].extract<log_category>().get()) == 0;
+       });
+}
+
+void set_log_level(const std::wstring& lvl)
+{
+       std::lock_guard<std::mutex> lock(get_filter_mutex());
+
+       if (boost::iequals(lvl, L"trace"))
+               get_level() = boost::log::trivial::trace;
+       else if (boost::iequals(lvl, L"debug"))
+               get_level() = boost::log::trivial::debug;
+       else if (boost::iequals(lvl, L"info"))
+               get_level() = boost::log::trivial::info;
+       else if (boost::iequals(lvl, L"warning"))
+               get_level() = boost::log::trivial::warning;
+       else if (boost::iequals(lvl, L"error"))
+               get_level() = boost::log::trivial::error;
+       else if (boost::iequals(lvl, L"fatal"))
+               get_level() = boost::log::trivial::fatal;
+
+       set_log_filter();
+}
+
+void set_log_category(const std::wstring& cat, bool enabled)
+{
+       log_category category_to_set;
+
+       if (boost::iequals(cat, L"calltrace"))
+               category_to_set = log_category::calltrace;
+       else if (boost::iequals(cat, L"communication"))
+               category_to_set = log_category::communication;
+       else
+               return; // Ignore
+
+       std::lock_guard<std::mutex> lock(get_filter_mutex());
+       auto& disabled_categories = get_disabled_categories();
+
+       if (enabled)
+               disabled_categories &= ~category_to_set;
+       else
+               disabled_categories |= category_to_set;
+
+       set_log_filter();
+}
+
+void print_child(
+               boost::log::trivial::severity_level level,
+               const std::wstring& indent,
+               const std::wstring& elem,
+               const boost::property_tree::wptree& tree)
+{
+       auto& data = tree.data();
+
+       if (!data.empty())
+               BOOST_LOG_STREAM_WITH_PARAMS(log::logger::get(), (boost::log::keywords::severity = level)) << indent << elem << L" " << replace_nonprintable_copy(data, L'?');
+       else if (tree.size() == 0)
+               BOOST_LOG_STREAM_WITH_PARAMS(log::logger::get(), (boost::log::keywords::severity = level)) << indent << elem;
+
+       for (auto& child : tree)
+               print_child(level, indent + (elem.empty() ? L"" : elem + L"."), child.first, child.second);
+}
+
+const char* remove_source_prefix(const char* file)
+{
+       auto found = boost::ifind_first(file, get_source_prefix().c_str());
+
+       if (found)
+               return found.end();
+       else
+               return file;
+}
+
+}}