Rietveld Code Review Tool
Help | Bug tracker | Discussion group | Source code

Side by Side Diff: src/plugin/PluginDebug.cpp

Issue 29323611: Issue #1234, #2058 - Rewrite log facility, improving thread implementation
Patch Set: rebase only Created Nov. 26, 2015, 1:07 p.m.
Left:
Right:
Use n/p to move between diff chunks; N/P to move between comments.
Jump to:
View unified diff | Download patch
« no previous file with comments | « src/plugin/PluginDebug.h ('k') | src/plugin/PluginMimeFilterClient.cpp » ('j') | no next file with comments »
Toggle Intra-line Diffs ('i') | Expand Comments ('e') | Collapse Comments ('c') | Show Comments Hide Comments ('s')
OLDNEW
1 /* 1 /*
2 * This file is part of Adblock Plus <https://adblockplus.org/>, 2 * This file is part of Adblock Plus <https://adblockplus.org/>,
3 * Copyright (C) 2006-2015 Eyeo GmbH 3 * Copyright (C) 2006-2015 Eyeo GmbH
4 * 4 *
5 * Adblock Plus is free software: you can redistribute it and/or modify 5 * Adblock Plus is free software: you can redistribute it and/or modify
6 * it under the terms of the GNU General Public License version 3 as 6 * it under the terms of the GNU General Public License version 3 as
7 * published by the Free Software Foundation. 7 * published by the Free Software Foundation.
8 * 8 *
9 * Adblock Plus is distributed in the hope that it will be useful, 9 * Adblock Plus is distributed in the hope that it will be useful,
10 * but WITHOUT ANY WARRANTY; without even the implied warranty of 10 * but WITHOUT ANY WARRANTY; without even the implied warranty of
11 * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the 11 * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
12 * GNU General Public License for more details. 12 * GNU General Public License for more details.
13 * 13 *
14 * You should have received a copy of the GNU General Public License 14 * You should have received a copy of the GNU General Public License
15 * along with Adblock Plus. If not, see <http://www.gnu.org/licenses/>. 15 * along with Adblock Plus. If not, see <http://www.gnu.org/licenses/>.
16 */ 16 */
17 17
18 #include "PluginStdAfx.h" 18 #include "PluginStdAfx.h"
19 #include "PluginDebug.h" 19 #include "PluginDebug.h"
20 #include "PluginClientBase.h" 20 #include "ActiveQueue.h"
21 #include "PluginMutex.h" 21 #include "PluginMutex.h"
22 #include "PluginClientBase.h"
23 #include "../shared/Utils.h" 22 #include "../shared/Utils.h"
23 #include <Windows.h>
24 #include <iomanip> 24 #include <iomanip>
25 #include <memory> 25 #include <memory>
26 26
27 namespace Trace
28 {
29 Location::Location(int id, int subId)
30 : prefixText()
31 {
32 std::ostringstream ss;
33 ss << "ErrorCode(" << id << "," << subId << ")";
34 postfixText = ss.str();
35 };
36 }
37
27 namespace 38 namespace
28 { 39 {
29 class CPluginDebugLock 40 class CPluginDebugLock
30 : public CPluginMutex 41 : public CPluginMutex
31 { 42 {
32 private: 43 private:
33 static CComAutoCriticalSection s_criticalSectionDebugLock; 44 static CComAutoCriticalSection s_criticalSectionDebugLock;
34 45
35 public: 46 public:
36 CPluginDebugLock() 47 CPluginDebugLock()
37 : CPluginMutex(L"DebugFile", PLUGIN_ERROR_MUTEX_DEBUG_FILE) 48 : CPluginMutex(L"DebugFile", PLUGIN_ERROR_MUTEX_DEBUG_FILE)
38 { 49 {
39 s_criticalSectionDebugLock.Lock(); 50 s_criticalSectionDebugLock.Lock();
40 } 51 }
41 52
42 ~CPluginDebugLock() 53 ~CPluginDebugLock()
43 { 54 {
44 s_criticalSectionDebugLock.Unlock(); 55 s_criticalSectionDebugLock.Unlock();
45 } 56 }
46 }; 57 };
47 58
48 CComAutoCriticalSection CPluginDebugLock::s_criticalSectionDebugLock; 59 CComAutoCriticalSection CPluginDebugLock::s_criticalSectionDebugLock;
49 60
61 /**
62 * The polymorphic part of a log entry.
63 */
50 class LogText 64 class LogText
51 { 65 {
52 public: 66 public:
53 virtual std::string Text() const = 0; 67 virtual std::string Text() const = 0;
54 virtual ~LogText() {}; 68 virtual ~LogText() {};
55 }; 69 };
56 70
57 class LogTextFixed 71 class LogTextFixed
58 : public LogText 72 : public LogText
59 { 73 {
(...skipping 41 matching lines...) Expand 10 before | Expand all | Expand 10 after
101 */ 115 */
102 struct SystemTime 116 struct SystemTime
103 : public SYSTEMTIME 117 : public SYSTEMTIME
104 { 118 {
105 SystemTime() 119 SystemTime()
106 { 120 {
107 ::GetSystemTime(static_cast<SYSTEMTIME*>(this)); 121 ::GetSystemTime(static_cast<SYSTEMTIME*>(this));
108 } 122 }
109 }; 123 };
110 124
125 /**
126 * Standard log entry, with variation in the data that generates the log messa ge.
127 */
111 class LogEntry 128 class LogEntry
112 { 129 {
113 const std::unique_ptr<LogText> text; 130 std::unique_ptr<LogText> text;
131
132 const Trace::Location location;
114 133
115 std::string InitialPrefix() const 134 std::string InitialPrefix() const
116 { 135 {
117 std::stringstream ss; 136 std::stringstream ss;
118 ss << std::setfill('0') << std::setw(2) << st.wHour; 137 ss << std::setfill('0') << std::setw(2) << st.wHour;
119 ss << ":"; 138 ss << ":";
120 ss << std::setfill('0') << std::setw(2) << st.wMinute; 139 ss << std::setfill('0') << std::setw(2) << st.wMinute;
121 ss << ":"; 140 ss << ":";
122 ss << std::setfill('0') << std::setw(2) << st.wSecond; 141 ss << std::setfill('0') << std::setw(2) << st.wSecond;
123 ss << "."; 142 ss << ".";
(...skipping 18 matching lines...) Expand all
142 /** 161 /**
143 * The process within which the log-generating statement executes. 162 * The process within which the log-generating statement executes.
144 */ 163 */
145 const DWORD processId; 164 const DWORD processId;
146 165
147 /** 166 /**
148 * The thread within which the log-generating statement executes. 167 * The thread within which the log-generating statement executes.
149 */ 168 */
150 const DWORD threadId; 169 const DWORD threadId;
151 170
152 explicit LogEntry(LogText* text) 171 explicit LogEntry(LogText* text, Trace::Location location)
153 : processId(::GetCurrentProcessId()), threadId(::GetCurrentThreadId()), te xt(text) 172 : text(text), location(location), processId(::GetCurrentProcessId()), thre adId(::GetCurrentThreadId())
154 {} 173 {}
155 174
156 LogEntry(LogText* text, DWORD processId, DWORD threadId) 175 /**
157 : processId(processId), threadId(threadId), text(text) 176 * Move constructor transfers 'text', copies everything else.
177 */
178 LogEntry(LogEntry&& x)
179 : text(std::move(x.text)), location(x.location), st(x.st), processId(x.pro cessId), threadId(x.threadId)
158 {} 180 {}
159 181
182 /**
183 * Copy constructor deleted.
184 */
185 LogEntry(const LogEntry&); // = delete
186
187 /**
188 * Copy assignment deleted.
189 */
190 LogEntry& operator=(const LogEntry&); // = delete
191
160 void Write(std::ostream& out) const 192 void Write(std::ostream& out) const
161 { 193 {
162 CPluginDebugLock lock; 194 CPluginDebugLock lock;
163 if (lock.IsLocked()) 195 if (lock.IsLocked())
164 { 196 {
165 auto lines = text->Text(); 197 auto lines = text->Text();
166 size_t linePosition = 0; 198 size_t linePosition = 0;
167 while (true) 199 while (true)
168 { 200 {
169 auto eolPosition = lines.find('\n', linePosition); 201 // Standard prefix, timestamp and thread ID
170 auto prefix = linePosition == 0 ? InitialPrefix() : SubsequentPrefix() ; 202 auto prefix = linePosition == 0 ? InitialPrefix() : SubsequentPrefix() ;
171 out << prefix; 203 out << prefix;
204
205 // Location prefix, if any
206 if (location.prefixText.length() > 0)
207 {
208 out << location.prefixText << " - ";
209 }
210
211 // One line of the log text itself
212 auto eolPosition = lines.find('\n', linePosition);
172 if (eolPosition == std::string::npos) 213 if (eolPosition == std::string::npos)
173 { 214 {
174 out << lines.substr(linePosition) << "\n"; 215 out << lines.substr(linePosition);
175 break;
176 } 216 }
177 else 217 else
178 { 218 {
179 out << lines.substr(linePosition, eolPosition - linePosition) << "\n "; 219 out << lines.substr(linePosition, eolPosition - linePosition);
180 linePosition = eolPosition + 1; 220 linePosition = eolPosition + 1;
181 } 221 }
222
223 // Location postfix, if any
224 if (location.postfixText.length() > 0)
225 {
226 out << " - ";
227 // Hack to deal with how gyp generates file names for Visual Studio
228 if (location.postfixText.find("..\\..\\") == 0)
229 {
230 out << location.postfixText.substr(6);
231 }
232 else
233 {
234 out << location.postfixText;
235 }
236 }
237 out << "\n";
238
239 // Check to see if that was the last line
240 if (eolPosition == std::string::npos)
241 {
242 break;
243 }
182 } 244 }
183 out.flush(); 245 out.flush();
184 } 246 }
185 } 247 }
186 248
187 void WriteFile(const std::wstring& logFileName) const 249 void WriteFile(const std::wstring& logFileName) const
188 { 250 {
189 std::ofstream out; 251 std::ofstream out;
190 out.open(logFileName, std::ios::app); 252 out.open(logFileName, std::ios::app);
191 Write(out); 253 Write(out);
(...skipping 10 matching lines...) Expand all
202 std::wstring debugFileName = GetDataPath(L"debug_" + std::to_wstring(le.proc essId) + L".txt"); 264 std::wstring debugFileName = GetDataPath(L"debug_" + std::to_wstring(le.proc essId) + L".txt");
203 le.WriteFile(debugFileName); 265 le.WriteFile(debugFileName);
204 } 266 }
205 267
206 void LogWriteResult(const LogEntry& le) 268 void LogWriteResult(const LogEntry& le)
207 { 269 {
208 std::wstring debugFileName = GetDataPath(L"debug_result.txt"); 270 std::wstring debugFileName = GetDataPath(L"debug_result.txt");
209 le.WriteFile(debugFileName); 271 le.WriteFile(debugFileName);
210 } 272 }
211 } 273 }
212 274
275 /**
276 * An active queue of 'LogEntry'.
277 * Life cycle is maintained in conjunction with 'LogQueueReference'.
278 */
279 class LogQueue
280 {
281 /**
282 * Processor for the log queue
283 */
284 static void ProcessLogEntry(const LogEntry&);
285
286 /**
287 * Active queue for processing log entries.
288 */
289 ActiveQueue<LogEntry, decltype(ProcessLogEntry)> queue;
290
291 public:
292 /**
293 * Insert an item into the queue.
294 */
295 static void Insert(LogEntry&& t)
296 {
297 /*
298 * Note that this function(indeed, this class) does not have the
299 * responsibility to ensure that an instance of the queue exists.
300 * See 'LogQueueReference' for the class that does.
301 * The non-null guard here is purely defensive;
302 * we shouldn't ever lose queued events because of it.
303 */
304 if (LogQueueReference::queueMasterReference)
305 {
306 LogQueueReference::queueMasterReference->queue.Insert(std::move(t));
307 }
308 }
309
310 LogQueue()
311 : queue(ProcessLogEntry)
312 {}
313 };
314
315 /**
316 * The processor for the log queue simply writes each log entry to its correspon ding log file.
317 *
318 * At present the only log entries that go through the queue also go to the defa ult log file.
319 * This logic will expand to include other log files as we pass all the log entr ies through the queue.
320 */
321 void LogQueue::ProcessLogEntry(const LogEntry& entry)
322 {
323 LogWriteDefault(entry);
324 }
325
326 /*
327 * Static initializations
328 */
329 LogQueueReference::pointer LogQueueReference::queueMasterReference;
330 std::mutex LogQueueReference::mutex;
331
332 /*
333 * Only initialize the instance reference within the constructor body,
334 * so that it's serialized under the protection of the mutex.
335 */
336 LogQueueReference::LogQueueReference()
337 : queueReference(queueMasterReference)
338 {
339 std::unique_lock<std::mutex> lock(LogQueueReference::mutex);
340 if (!queueMasterReference)
341 {
342 queueMasterReference = pointer(new LogQueue());
343 LogQueue::Insert(LogEntry(new LogTextFixed("LogQueue start"), HERE_F));
344 }
345 queueReference = queueMasterReference;
346 }
347
348 LogQueueReference::~LogQueueReference()
349 {
350 std::unique_lock<std::mutex> lock(LogQueueReference::mutex);
351 queueReference.reset();
352 if (queueMasterReference.use_count() == 1)
353 {
354 LogQueue::Insert(LogEntry(new LogTextFixed("LogQueue stop"), HERE_F));
355 queueMasterReference.reset();
356 }
357 }
358
359
213 #ifdef ENABLE_DEBUG_INFO 360 #ifdef ENABLE_DEBUG_INFO
214 361
215 void CPluginDebug::Debug(const std::string& text) 362 void CPluginDebug::Debug(const std::string& text)
216 { 363 {
217 LogWriteDefault(LogEntry(new LogTextFixed(text))); 364 LogWriteDefault(LogEntry(new LogTextFixed(text), Trace::Location()));
218 } 365 }
219 366
220 void CPluginDebug::Debug(const std::wstring& text) 367 void CPluginDebug::Debug(const std::wstring& text)
221 { 368 {
222 Debug(ToUtf8String(text)); 369 Debug(ToUtf8String(text));
223 } 370 }
224 371
225 #endif 372 #endif
226 373
227 void CPluginDebug::DebugSystemException(const std::system_error& ex, int errorId , int errorSubid, const std::string& description) 374 namespace Trace
228 { 375 {
229 std::string message = description + ", " + ex.code().message() + ", " + ex.wha t(); 376 void SystemException(const std::system_error& ex, const std::string& descripti on, Trace::Location location)
230 DEBUG_ERROR_LOG(ex.code().value(), errorId, errorSubid, message); 377 {
378 std::string message = description + ", " + ex.code().message() + ", " + ex.w hat();
379 ErrorCode(ex.code().value(), message, location);
380 }
231 } 381 }
232 382
233 #if (defined ENABLE_DEBUG_INFO) 383 #if (defined ENABLE_DEBUG_INFO)
234 384
235 void CPluginDebug::DebugException(const std::exception& ex) 385 void CPluginDebug::DebugException(const std::exception& ex, Trace::Location loca tion)
236 { 386 {
237 auto lt = new LogTextFixed(ex); 387 auto lt = new LogTextFixed(ex);
238 LogEntry le(lt); 388 LogEntry le(lt, location);
239 #ifdef ENABLE_DEBUG_ERROR
240 LogWriteDefault(le); 389 LogWriteDefault(le);
241 #endif
242 DEBUG_SELFTEST(
243 "*************************************************************************** *****\n"
244 + lt->text() + "\n"
245 "*************************************************************************** *****")
246 } 390 }
247 391
248 void CPluginDebug::DebugErrorCode(DWORD errorCode, const std::string& error, DWO RD processId, DWORD threadId) 392 void CPluginDebug::DebugErrorCode(DWORD errorCode, const std::string& error, Tra ce::Location location)
249 { 393 {
250 auto lt = new LogTextErrorCode(errorCode, error); 394 auto lt = new LogTextErrorCode(errorCode, error);
251 LogEntry le(lt, processId, threadId); 395 LogEntry le(lt, location);
252 #ifdef ENABLE_DEBUG_ERROR
253 LogWriteDefault(le); 396 LogWriteDefault(le);
254 #endif
255 DEBUG_SELFTEST(
256 "*************************************************************************** *****\n"
257 + lt->text() + "\n"
258 "*************************************************************************** *****")
259 } 397 }
260 398
261 #endif 399 #endif
262 400
263 // ============================================================================ 401 // ============================================================================
264 // Debug result 402 // Debug result
265 // ============================================================================ 403 // ============================================================================
266 404
267 #ifdef ENABLE_DEBUG_RESULT 405 #ifdef ENABLE_DEBUG_RESULT
268 406
269 void CPluginDebug::DebugResult(const std::wstring& text) 407 void CPluginDebug::DebugResult(const std::wstring& text)
270 { 408 {
271 LogWriteResult(LogEntry(new LogTextFixed(ToUtf8String(text)))); 409 LogWriteResult(LogEntry(new LogTextFixed(ToUtf8String(text)), Trace::Location( )));
272 } 410 }
273 411
274 void CPluginDebug::DebugResultDomain(const std::wstring& domain) 412 void CPluginDebug::DebugResultDomain(const std::wstring& domain)
275 { 413 {
276 DebugResult( 414 DebugResult(
277 L"========================================================================== ===============\n" 415 L"========================================================================== ===============\n"
278 + domain + L"\n" 416 + domain + L"\n"
279 L"========================================================================== ==============="); 417 L"========================================================================== ===============");
280 } 418 }
281 419
(...skipping 18 matching lines...) Expand all
300 r += s.substr(n - 30, 30); 438 r += s.substr(n - 30, 30);
301 return r; 439 return r;
302 } 440 }
303 } 441 }
304 442
305 void CPluginDebug::DebugResultBlocking(const std::wstring& type, const std::wstr ing& src, const std::wstring& domain) 443 void CPluginDebug::DebugResultBlocking(const std::wstring& type, const std::wstr ing& src, const std::wstring& domain)
306 { 444 {
307 DebugResultFormat(L"Blocked", type, domain.empty() ? L"-" : domain, Shorten(sr c)); 445 DebugResultFormat(L"Blocked", type, domain.empty() ? L"-" : domain, Shorten(sr c));
308 } 446 }
309 447
310
311 void CPluginDebug::DebugResultHiding(const std::wstring& tag, const std::wstring & id, const std::wstring& filter) 448 void CPluginDebug::DebugResultHiding(const std::wstring& tag, const std::wstring & id, const std::wstring& filter)
312 { 449 {
313 DebugResultFormat(L"Hidden", tag, L"- " + Shorten(id), filter); 450 DebugResultFormat(L"Hidden", tag, L"- " + Shorten(id), filter);
314 } 451 }
315 452
316 #endif // ENABLE_DEBUG_RESULT 453 #endif // ENABLE_DEBUG_RESULT
317 454
318
319 #ifdef ENABLE_DEBUG_RESULT_IGNORED 455 #ifdef ENABLE_DEBUG_RESULT_IGNORED
320 456
321 void CPluginDebug::DebugResultIgnoring(const std::wstring& type, const std::wstr ing& src, const std::wstring& domain) 457 void CPluginDebug::DebugResultIgnoring(const std::wstring& type, const std::wstr ing& src, const std::wstring& domain)
322 { 458 {
323 DebugResultFormat(L"Ignored", type, domain.empty() ? L"-" : domain, Shorten(sr c)); 459 DebugResultFormat(L"Ignored", type, domain.empty() ? L"-" : domain, Shorten(sr c));
324 } 460 }
325 461
326 #endif // ENABLE_DEBUG_RESULT_IGNORED 462 #endif // ENABLE_DEBUG_RESULT_IGNORED
463
464 void Trace::ErrorCode(DWORD errorCode, const std::string& description, Trace::Lo cation location)
465 {
466 LogQueue::Insert(LogEntry(new LogTextErrorCode(errorCode, description), locati on));
467 }
468
469 void Trace::TextFixed(const std::string& description, Trace::Location location)
470 {
471 LogQueue::Insert(LogEntry(new LogTextFixed(description), location));
472 }
OLDNEW
« no previous file with comments | « src/plugin/PluginDebug.h ('k') | src/plugin/PluginMimeFilterClient.cpp » ('j') | no next file with comments »

Powered by Google App Engine
This is Rietveld