]> git.sesse.net Git - casparcg/blob - common/log.cpp
Write timestamp, thread and severity on each line in a multiline log statement, not...
[casparcg] / common / log.cpp
1 /*
2 * Copyright (c) 2011 Sveriges Television AB <info@casparcg.com>
3 *
4 * This file is part of CasparCG (www.casparcg.com).
5 *
6 * CasparCG is free software: you can redistribute it and/or modify
7 * it under the terms of the GNU General Public License as published by
8 * the Free Software Foundation, either version 3 of the License, or
9 * (at your option) any later version.
10 *
11 * CasparCG is distributed in the hope that it will be useful,
12 * but WITHOUT ANY WARRANTY; without even the implied warranty of
13 * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
14 * GNU General Public License for more details.
15 *
16 * You should have received a copy of the GNU General Public License
17 * along with CasparCG. If not, see <http://www.gnu.org/licenses/>.
18 *
19 * Author: Robert Nagy, ronag89@gmail.com
20 */
21
22 #include "stdafx.h"
23
24 #include "log.h"
25
26 #include "except.h"
27 #include "utf.h"
28
29 #include <ios>
30 #include <iomanip>
31 #include <string>
32 #include <ostream>
33
34 #include <boost/shared_ptr.hpp>
35 #include <boost/make_shared.hpp>
36 #include <boost/filesystem/convenience.hpp>
37 #include <boost/date_time/posix_time/posix_time.hpp>
38 #include <boost/algorithm/string.hpp>
39
40 #include <boost/log/core.hpp>
41 #include <boost/log/trivial.hpp>
42 #include <boost/log/expressions.hpp>
43
44 #include <boost/log/sinks/text_file_backend.hpp>
45 #include <boost/log/sinks/text_ostream_backend.hpp>
46 #include <boost/log/sinks/sync_frontend.hpp>
47 #include <boost/log/sinks/async_frontend.hpp>
48 #include <boost/log/core/record.hpp>
49 #include <boost/log/attributes/attribute_value.hpp>
50 #include <boost/log/attributes/current_thread_id.hpp>
51 #include <boost/log/utility/setup/common_attributes.hpp>
52
53 #include <boost/core/null_deleter.hpp>
54 #include <boost/lambda/lambda.hpp>
55 #include <boost/bind.hpp>
56 #include <boost/lexical_cast.hpp>
57 #include <boost/property_tree/ptree.hpp>
58
59 #include <tbb/atomic.h>
60
61 namespace caspar { namespace log {
62
63 using namespace boost;
64
65 template<typename Stream>
66 void append_timestamp(Stream& stream)
67 {
68         auto timestamp = boost::posix_time::microsec_clock::local_time();
69         auto date = timestamp.date();
70         auto time = timestamp.time_of_day();
71         auto milliseconds = time.fractional_seconds() / 1000; // microseconds to milliseconds
72
73         std::wstringstream buffer;
74
75         buffer
76                 << std::setfill(L'0')
77                 << L"["
78                 << std::setw(4) << date.year() << L"-" << std::setw(2) << date.month().as_number() << "-" << std::setw(2) << date.day().as_number()
79                 << L" "
80                 << std::setw(2) << time.hours() << L":" << std::setw(2) << time.minutes() << L":" << std::setw(2) << time.seconds()
81                 << L"."
82                 << std::setw(3) << milliseconds
83                 << L"] ";
84
85         stream << buffer.str();
86 }
87
88 class column_writer
89 {
90         tbb::atomic<int> column_width_;
91 public:
92         column_writer(int initial_width = 0)
93         {
94                 column_width_ = initial_width;
95         }
96
97         template<typename Stream, typename Val>
98         void write(Stream& out, const Val& value)
99         {
100                 std::wstring to_string = boost::lexical_cast<std::wstring>(value);
101                 int length = static_cast<int>(to_string.size());
102                 int read_width;
103
104                 while ((read_width = column_width_) < length && column_width_.compare_and_swap(length, read_width) != read_width);
105                 read_width = column_width_;
106
107                 out << L"[" << to_string << L"] ";
108
109                 for (int n = 0; n < read_width - length; ++n)
110                         out << L" ";
111         }
112 };
113
114 template<typename Stream>
115 void my_formatter(bool print_all_characters, const boost::log::record_view& rec, Stream& strm)
116 {
117         static column_writer thread_id_column;
118         static column_writer severity_column(7);
119         namespace expr = boost::log::expressions;
120
121         std::wstringstream pre_message_stream;
122         append_timestamp(pre_message_stream);
123         thread_id_column.write(pre_message_stream, boost::log::extract<boost::log::attributes::current_thread_id::value_type>("ThreadID", rec).get().native_id());
124         severity_column.write(pre_message_stream, boost::log::extract<boost::log::trivial::severity_level>("Severity", rec));
125
126         auto pre_message = pre_message_stream.str();
127
128         strm << pre_message;
129
130         auto line_break_replacement = L"\n" + pre_message;
131
132         if (print_all_characters)
133         {
134                 strm << boost::replace_all_copy(rec[expr::message].get<std::wstring>(), "\n", line_break_replacement);
135         }
136         else
137         {
138                 strm << boost::replace_all_copy(replace_nonprintable_copy(rec[expr::message].get<std::wstring>(), L'?'), L"\n", line_break_replacement);
139         }
140 }
141
142 namespace internal{
143         
144 void init()
145 {       
146         boost::log::add_common_attributes();
147         typedef boost::log::sinks::asynchronous_sink<boost::log::sinks::wtext_ostream_backend> stream_sink_type;
148
149         auto stream_backend = boost::make_shared<boost::log::sinks::wtext_ostream_backend>();
150         stream_backend->add_stream(boost::shared_ptr<std::wostream>(&std::wcout, boost::null_deleter()));
151         stream_backend->auto_flush(true);
152
153         auto stream_sink = boost::make_shared<stream_sink_type>(stream_backend);
154
155         bool print_all_characters = false;
156         stream_sink->set_formatter(boost::bind(&my_formatter<boost::log::wformatting_ostream>, print_all_characters, _1, _2));
157
158         boost::log::core::get()->add_sink(stream_sink);
159 }
160
161 }
162
163 void add_file_sink(const std::wstring& folder)
164 {
165         typedef boost::log::sinks::synchronous_sink<boost::log::sinks::text_file_backend> file_sink_type;
166
167         try
168         {
169                 if (!boost::filesystem::is_directory(folder))
170                         CASPAR_THROW_EXCEPTION(directory_not_found());
171
172                 auto file_sink = boost::make_shared<file_sink_type>(
173                         boost::log::keywords::file_name = (folder + L"caspar_%Y-%m-%d.log"),
174                         boost::log::keywords::time_based_rotation = boost::log::sinks::file::rotation_at_time_point(0, 0, 0),
175                         boost::log::keywords::auto_flush = true,
176                         boost::log::keywords::open_mode = std::ios::app
177                         );
178
179                 bool print_all_characters = true;
180
181                 file_sink->set_formatter(boost::bind(&my_formatter<boost::log::formatting_ostream>, print_all_characters, _1, _2));
182                 boost::log::core::get()->add_sink(file_sink);
183         }
184         catch (...)
185         {
186                 std::wcerr << L"Failed to Setup File Logging Sink" << std::endl << std::endl;
187         }
188 }
189
190 std::shared_ptr<void> add_preformatted_line_sink(std::function<void(std::string line)> formatted_line_sink)
191 {
192         class sink_backend : public boost::log::sinks::basic_formatted_sink_backend<char>
193         {
194                 std::function<void(std::string line)> formatted_line_sink_;
195         public:
196                 sink_backend(std::function<void(std::string line)> formatted_line_sink)
197                         : formatted_line_sink_(std::move(formatted_line_sink))
198                 {
199                 }
200
201                 void consume(const boost::log::record_view& rec, const std::string& formatted_message)
202                 {
203                         try
204                         {
205                                 formatted_line_sink_(formatted_message);
206                         }
207                         catch (...)
208                         {
209                                 std::cerr << "[sink_backend] Error while consuming formatted message: " << formatted_message << std::endl << std::endl;
210                         }
211                 }
212         };
213
214         typedef boost::log::sinks::synchronous_sink<sink_backend> sink_type;
215
216         auto sink = boost::make_shared<sink_type>(std::move(formatted_line_sink));
217         bool print_all_characters = true;
218
219         sink->set_formatter(boost::bind(&my_formatter<boost::log::formatting_ostream>, print_all_characters, _1, _2));
220
221         boost::log::core::get()->add_sink(sink);
222
223         return std::shared_ptr<void>(nullptr, [=](void*)
224         {
225                 boost::log::core::get()->remove_sink(sink);
226         });
227 }
228
229 void set_log_level(const std::wstring& lvl)
230 {
231         if (boost::iequals(lvl, L"trace"))
232                 boost::log::core::get()->set_filter(boost::log::trivial::severity >= boost::log::trivial::trace);
233         else if (boost::iequals(lvl, L"debug"))
234                 boost::log::core::get()->set_filter(boost::log::trivial::severity >= boost::log::trivial::debug);
235         else if (boost::iequals(lvl, L"info"))
236                 boost::log::core::get()->set_filter(boost::log::trivial::severity >= boost::log::trivial::info);
237         else if (boost::iequals(lvl, L"warning"))
238                 boost::log::core::get()->set_filter(boost::log::trivial::severity >= boost::log::trivial::warning);
239         else if (boost::iequals(lvl, L"error"))
240                 boost::log::core::get()->set_filter(boost::log::trivial::severity >= boost::log::trivial::error);
241         else if (boost::iequals(lvl, L"fatal"))
242                 boost::log::core::get()->set_filter(boost::log::trivial::severity >= boost::log::trivial::fatal);
243 }
244
245 void print_child(
246                 boost::log::trivial::severity_level level,
247                 const std::wstring& indent,
248                 const std::wstring& elem,
249                 const boost::property_tree::wptree& tree)
250 {
251         auto& data = tree.data();
252
253         if (!data.empty())
254                 BOOST_LOG_STREAM_WITH_PARAMS(log::logger::get(), (boost::log::keywords::severity = level)) << indent << elem << L" " << replace_nonprintable_copy(data, L'?');
255         else if (tree.size() == 0)
256                 BOOST_LOG_STREAM_WITH_PARAMS(log::logger::get(), (boost::log::keywords::severity = level)) << indent << elem;
257
258         for (auto& child : tree)
259                 print_child(level, indent + (elem.empty() ? L"" : elem + L"."), child.first, child.second);
260 }
261
262 }}