Issue 5187613258416128: Issue #1234 - Rewrite internals of debug facility (Closed)
DescriptionIssue #1234 - Rewrite internals of debug facility
Eliminate CString from implementation of debug logging functions. Rewrite the
internals as part of this process. Add thread id to accompany the timestamp.
Suppressed the prefix on multiple-line log texts.
Eliminate dead code and moribund code, including logging to console, non-split
debug files. Remove file "Console.h". Removed the distinction between "_ui"
and "_thread" log files, which enabled removing tracking of current thread in
'CPluginSettings'.
Moved 'GetDataPath()' from "PluginSettings.*" into "PluginDebug.cpp", the only
place it was used.
Patch Set 1 : #
Total comments: 11
Patch Set 2 : capitalize a function name #
Total comments: 22
Patch Set 3 : rebase + address comments #
Total comments: 4
Patch Set 4 : small fixes from comment #7 #Patch Set 5 : rebase to current public tip #
Total comments: 10
Patch Set 6 : rebase only; no other changes #Patch Set 7 : add virtual destructor to LogText #
Total comments: 2
Patch Set 8 : rebase only #
Total comments: 10
MessagesTotal messages: 30
1) New class 'LogEntry' has a number of interlocking advantages. * It combines both of the functions that write to debug files into a single place, using a common entry format. It's much easier to write new kinds of trace logging, if we want. It also meant I could get a comment entry format without writing an explicit replacement for 'CString::Tokenize'. * The format in "debug_result.txt" could now be easily rewritten to use multiple lines, which might improve readability. * We have a facility for deferred logging of certain errors that's not in PluginDebug.* at all. It's in PluginClientBase.* (This is the legacy file name; 'CPluginClient' no longer derives from base class.) There's a queuing facility for creating a log entry in one thread and writing it out on another one. 'LogQueue' does the queuing and class 'CPluginError' is the type of the queue elements. 'LogEntry' is prepared as a replacement for 'CPluginError'. This will allow us to rewrite 'LogQueue' at some point to be able to defer the writing of log entries for any entry. This would eliminate any I/O delays incurred when tracing time-sensitive entry points. This was also the main reason to virtualize the text content of 'LogEntry', so that it could be computed at the time of writing the entry rather than the time of its creation. This change set does not include a rewrite of 'LogQueue'. 2) 'LogEntry' has two constructors. The one with explicit 'processId' and 'threadId' arguments is only present to support the legacy 'CPluginError', which stores its own values for these. 3) The existing code has a race defect. If two log entries in any process (not just different threads in a single process) try to write to their log files at the same time, one gets dropped silently. I did not fix this defect in the present change set. It's a low-impact defect, since it only affects developers, and rarely at that. This fix can be done during a rewrite of 'LogQueue', which will have to deal with same synchronization issues anyway. 4) In class 'LogEntry', I separated 'Write' and 'WriteFile' with the intention of adding unit tests, but didn't get to writing unit tests. I'd still prefer to keep them separate functions. 5) Do we still need DEBUG_SELFTEST? It's defined to empty in Config.h and seems to be an artifact of early development.
Looks good overall. Just some suggestions. http://codereview.adblockplus.org/5187613258416128/diff/5668600916475904/src/... File src/plugin/PluginClass.cpp (left): http://codereview.adblockplus.org/5187613258416128/diff/5668600916475904/src/... src/plugin/PluginClass.cpp:633: wsprintf(tmp, L"Invoke: %d\n", dispidMember); How about switching to swprintf_s here. Seems like an appropriate changeset for this http://codereview.adblockplus.org/5187613258416128/diff/5668600916475904/src/... File src/plugin/PluginDebug.cpp (right): http://codereview.adblockplus.org/5187613258416128/diff/5668600916475904/src/... src/plugin/PluginDebug.cpp:51: virtual std::string text() =0; Method names should start with a capital letter. Also, a space after '=' would be nice http://codereview.adblockplus.org/5187613258416128/diff/5668600916475904/src/... src/plugin/PluginDebug.cpp:145: return " + "; NIT: Just spaces without + would look better, IMO. http://codereview.adblockplus.org/5187613258416128/diff/5668600916475904/src/... src/plugin/PluginDebug.cpp:304: std::wstring Shorten(const std::wstring& s) Kind of ambiguous name, IMO. How about DebugShortenString?
New patch set to follow. http://codereview.adblockplus.org/5187613258416128/diff/5668600916475904/src/... File src/plugin/PluginClass.cpp (left): http://codereview.adblockplus.org/5187613258416128/diff/5668600916475904/src/... src/plugin/PluginClass.cpp:633: wsprintf(tmp, L"Invoke: %d\n", dispidMember); On 2015/03/19 03:46:12, Oleksandr wrote: > How about switching to swprintf_s here. Seems like an appropriate changeset for > this I need to rebase this change set. There's no analogous statement in the current tip; it was eliminated when the present IDispatch was split up. http://codereview.adblockplus.org/5187613258416128/diff/5668600916475904/src/... File src/plugin/PluginDebug.cpp (right): http://codereview.adblockplus.org/5187613258416128/diff/5668600916475904/src/... src/plugin/PluginDebug.cpp:51: virtual std::string text() =0; On 2015/03/19 03:46:12, Oleksandr wrote: > Method names should start with a capital letter. Also, a space after '=' would > be nice I'll fix the function name. There's an old convention that "=0" (no spaces) is the signal for a pure virtual function declaration in C++. http://codereview.adblockplus.org/5187613258416128/diff/5668600916475904/src/... src/plugin/PluginDebug.cpp:145: return " + "; On 2015/03/19 03:46:12, Oleksandr wrote: > NIT: Just spaces without + would look better, IMO. This is something of an existing convention in multiple-line log message, that there's a marker for a continuation line. We have "-" in that column already marking the first line. I added a "+" to clearly mark that it was a subsequent line. Here's a sample of what it looks like: (Make sure to widen the window so it doesn't wrap.) 14:41:24.219 [ 2476] - CPluginClass::<constructor>, this = 003a4180 14:41:24.224 [11388] - ================================================================================ + TAB THREAD process=1259211388 + ================================================================================ 14:41:24.225 [ 2476] - ================================================================================ + NEW TAB UI + ================================================================================ 14:41:24.227 [ 2476] - CPluginClass::SetSite, this = 003a4180, browser = 0037b624 - Loaded as BHO 14:41:24.230 [ 8276] - InitObject http://codereview.adblockplus.org/5187613258416128/diff/5668600916475904/src/... src/plugin/PluginDebug.cpp:304: std::wstring Shorten(const std::wstring& s) On 2015/03/19 03:46:12, Oleksandr wrote: > Kind of ambiguous name, IMO. How about DebugShortenString? I'd worry about it if it wasn't in anonymous namespace and declared immediately before use.
New patch set addresses Oleksandr's comments. Well, at least the one I agreed with. http://codereview.adblockplus.org/5187613258416128/diff/5668600916475904/src/... File src/plugin/PluginDebug.cpp (right): http://codereview.adblockplus.org/5187613258416128/diff/5668600916475904/src/... src/plugin/PluginDebug.cpp:145: return " + "; On 2015/03/19 12:56:35, Eric wrote: > (Make sure to widen the window so it doesn't wrap.) So much for that good intention. You can see the full-width version in a wide-enough text area while editing a reply. http://codereview.adblockplus.org/5187613258416128/diff/5717271485874176/src/... File src/plugin/PluginDebug.cpp (right): http://codereview.adblockplus.org/5187613258416128/diff/5717271485874176/src/... src/plugin/PluginDebug.cpp:65: virtual std::string Text() override I remembered to look this up. VS 2012 does support the contextual keyword "override".
http://codereview.adblockplus.org/5187613258416128/diff/5668600916475904/src/... File src/plugin/PluginDebug.cpp (right): http://codereview.adblockplus.org/5187613258416128/diff/5668600916475904/src/... src/plugin/PluginDebug.cpp:51: virtual std::string text() =0; This "no spaces" is not necessary, I also expect to have a space here. http://codereview.adblockplus.org/5187613258416128/diff/5717271485874176/src/... File src/plugin/PluginDebug.cpp (right): http://codereview.adblockplus.org/5187613258416128/diff/5717271485874176/src/... src/plugin/PluginDebug.cpp:51: virtual std::string Text() =0; I guess, the method should have const modifier. http://codereview.adblockplus.org/5187613258416128/diff/5717271485874176/src/... src/plugin/PluginDebug.cpp:61: LogTextFixed(std::string text) explicit and const ref are missed http://codereview.adblockplus.org/5187613258416128/diff/5717271485874176/src/... src/plugin/PluginDebug.cpp:100: : ex(ex) I'm not sure that it is safe to copy std::exception because we can lose the information if there is some DerivedException. What about replacing LogText and derived classes by functions `std::string FormatToDebugString(const std::exception& ex)` and `std::string FormatToDebugString(DWORD errorCode, const std::string& text)` and make LogEntry constructor to accept `const std::string&` instead of LogText*? http://codereview.adblockplus.org/5187613258416128/diff/5717271485874176/src/... src/plugin/PluginDebug.cpp:164: LogEntry(LogText* text) explicit is missed http://codereview.adblockplus.org/5187613258416128/diff/5717271485874176/src/... src/plugin/PluginDebug.cpp:172: void Write(std::ostream& out) this method should be const http://codereview.adblockplus.org/5187613258416128/diff/5717271485874176/src/... src/plugin/PluginDebug.cpp:199: void WriteFile(const std::wstring& logFileName) it also should be const http://codereview.adblockplus.org/5187613258416128/diff/5717271485874176/src/... src/plugin/PluginDebug.cpp:212: void LogWriteDefault(LogEntry& le) LogEntry should be const ref http://codereview.adblockplus.org/5187613258416128/diff/5717271485874176/src/... src/plugin/PluginDebug.cpp:218: void LogWriteResult(LogEntry& le) it also should be const
Patch set 3 addresses Sergei's comments. http://codereview.adblockplus.org/5187613258416128/diff/5668600916475904/src/... File src/plugin/PluginDebug.cpp (right): http://codereview.adblockplus.org/5187613258416128/diff/5668600916475904/src/... src/plugin/PluginDebug.cpp:51: virtual std::string text() =0; On 2015/03/30 13:45:26, sergei wrote: > This "no spaces" is not necessary, I also expect to have a space here. Done. http://codereview.adblockplus.org/5187613258416128/diff/5717271485874176/src/... File src/plugin/PluginDebug.cpp (right): http://codereview.adblockplus.org/5187613258416128/diff/5717271485874176/src/... src/plugin/PluginDebug.cpp:51: virtual std::string Text() =0; On 2015/03/30 13:45:26, sergei wrote: > I guess, the method should have const modifier. Done. http://codereview.adblockplus.org/5187613258416128/diff/5717271485874176/src/... src/plugin/PluginDebug.cpp:61: LogTextFixed(std::string text) On 2015/03/30 13:45:26, sergei wrote: > explicit and const ref are missed We don't have 'explict' in VS 2012. 'const' done. http://codereview.adblockplus.org/5187613258416128/diff/5717271485874176/src/... src/plugin/PluginDebug.cpp:100: : ex(ex) On 2015/03/30 13:45:26, sergei wrote: > What about replacing LogText and derived classes by functions [...] The point behind subclassing LogText is to defer calculation of the log string until it's time to write to the log. In general, the thread that the class is instantiated in won't be the same as writes to the log. See my initial comment #1 above for more. http://codereview.adblockplus.org/5187613258416128/#msg1 http://codereview.adblockplus.org/5187613258416128/diff/5717271485874176/src/... src/plugin/PluginDebug.cpp:100: : ex(ex) On 2015/03/30 13:45:26, sergei wrote: > I'm not sure that it is safe to copy std::exception because we can lose the > information if there is some DerivedException. You're right; it's not. There's also no 'clone()' member of 'std::exception'. I've eliminated the class and added another constructor to 'LogTextFixed'. It evaluates 'what()' in the constructor, which I don't like, but it will be adequate for now. The alternative is to use 'make_exception_ptr' and 'rethrow_exception', which is overkill for what we need at this point. If we ever need very high performance for queuing a log entry, such as for a DLL entry point, we can implement it then. http://codereview.adblockplus.org/5187613258416128/diff/5717271485874176/src/... src/plugin/PluginDebug.cpp:164: LogEntry(LogText* text) On 2015/03/30 13:45:26, sergei wrote: > explicit is missed No 'explicit' in VS 2012. http://codereview.adblockplus.org/5187613258416128/diff/5717271485874176/src/... src/plugin/PluginDebug.cpp:172: void Write(std::ostream& out) On 2015/03/30 13:45:26, sergei wrote: > this method should be const Done. http://codereview.adblockplus.org/5187613258416128/diff/5717271485874176/src/... src/plugin/PluginDebug.cpp:199: void WriteFile(const std::wstring& logFileName) On 2015/03/30 13:45:26, sergei wrote: > it also should be const Done. http://codereview.adblockplus.org/5187613258416128/diff/5717271485874176/src/... src/plugin/PluginDebug.cpp:212: void LogWriteDefault(LogEntry& le) On 2015/03/30 13:45:26, sergei wrote: > LogEntry should be const ref Done. http://codereview.adblockplus.org/5187613258416128/diff/5717271485874176/src/... src/plugin/PluginDebug.cpp:218: void LogWriteResult(LogEntry& le) On 2015/03/30 13:45:26, sergei wrote: > it also should be const Done.
http://codereview.adblockplus.org/5187613258416128/diff/5717271485874176/src/... File src/plugin/PluginDebug.cpp (right): http://codereview.adblockplus.org/5187613258416128/diff/5717271485874176/src/... src/plugin/PluginDebug.cpp:61: LogTextFixed(std::string text) On 2015/03/31 15:42:22, Eric wrote: > On 2015/03/30 13:45:26, sergei wrote: > > explicit and const ref are missed > > We don't have 'explict' in VS 2012. > > 'const' done. Why do we not have explicit in VS 2012? It's a good practice and according to our code style it should be used for constructors with one argument if it's not a copy constructor. http://codereview.adblockplus.org/5187613258416128/diff/5717271485874176/src/... src/plugin/PluginDebug.cpp:100: : ex(ex) On 2015/03/31 15:42:22, Eric wrote: > On 2015/03/30 13:45:26, sergei wrote: > > I'm not sure that it is safe to copy std::exception because we can lose the > > information if there is some DerivedException. > > You're right; it's not. There's also no 'clone()' member of 'std::exception'. > > I've eliminated the class and added another constructor to 'LogTextFixed'. It > evaluates 'what()' in the constructor, which I don't like, but it will be > adequate for now. The alternative is to use 'make_exception_ptr' and > 'rethrow_exception', which is overkill for what we need at this point. If we > ever need very high performance for queuing a log entry, such as for a DLL entry > point, we can implement it then. It's clear, but I would say lazy evaluation here makes insignificant contribution. However, I think it could be useful to have LogEntry structure (without inheritance) where we can also store the function name, file name, line number, thread ID and other useful information of the log caller. http://codereview.adblockplus.org/5187613258416128/diff/5693417237512192/src/... File src/plugin/PluginDebug.cpp (right): http://codereview.adblockplus.org/5187613258416128/diff/5693417237512192/src/... src/plugin/PluginDebug.cpp:246: auto lt = new LogTextErrorCode(errorCode, error); Here and above, who will destroy it if ENABLE_DEBUG_ERROR is not defined? Let's make it as std::unique_ptr or allocate a plain structure on the stack (see comment about lazy loading). http://codereview.adblockplus.org/5187613258416128/diff/5693417237512192/src/... src/plugin/PluginDebug.cpp:252: + lt.text() + "\n" should it be `lt->`?
http://codereview.adblockplus.org/5187613258416128/diff/5717271485874176/src/... File src/plugin/PluginDebug.cpp (right): http://codereview.adblockplus.org/5187613258416128/diff/5717271485874176/src/... src/plugin/PluginDebug.cpp:61: LogTextFixed(std::string text) On 2015/04/02 07:41:12, sergei wrote: > Why do we not have explicit in VS 2012? I'm confused. We don't have 'explicit' for conversion operators. We do for constructors. > It's a good practice It's good practice when there's a possibility of unwanted implicit conversion operations. There's not such possibility here. Barring that possibility, the extra declaration is junk syntax. > according to > our code style it should be used for constructors with one argument if it's not > a copy constructor. Yes, that also true. I had to look it up, though. While I still think it's junk syntax, I've added it. http://codereview.adblockplus.org/5187613258416128/diff/5717271485874176/src/... src/plugin/PluginDebug.cpp:100: : ex(ex) On 2015/04/02 07:41:12, sergei wrote: > It's clear, but I would say lazy evaluation here makes insignificant > contribution. I'll leave it in. It's not harming anything. I may need it later and I don't want an extensive rewrite in the present change set. > However, I think it could be useful to have LogEntry structure > (without inheritance) where we can also store the function name, file name, line > number, thread ID and other useful information of the log caller. Perhaps this should all go in the 'LogEntry' class, perhaps not. There's some more rewriting of the debug facilities to do first. When that all falls out, it may be clearer. One thing that is clear to me, though, is that we can get something stack traces by using our own exception classes with function/file/line information and using nested exceptions. In that case the top level exception provides information we don't need duplicated in the log. Other kinds of log messages, though, would still need them. The upshot is that I'm going to finish the debug facility generally before I consider those next steps. http://codereview.adblockplus.org/5187613258416128/diff/5693417237512192/src/... File src/plugin/PluginDebug.cpp (right): http://codereview.adblockplus.org/5187613258416128/diff/5693417237512192/src/... src/plugin/PluginDebug.cpp:246: auto lt = new LogTextErrorCode(errorCode, error); On 2015/04/02 07:41:12, sergei wrote: > Here and above, who will destroy it if ENABLE_DEBUG_ERROR is not defined? Fixed. http://codereview.adblockplus.org/5187613258416128/diff/5693417237512192/src/... src/plugin/PluginDebug.cpp:252: + lt.text() + "\n" On 2015/04/02 07:41:12, sergei wrote: > should it be `lt->`? Fixed. It should also be that we just eliminate DEBUG_SELFTEST entirely. I don't think it's been used in years; it looks like an artifact of the initial stages of development of these logging functions.
New patch set, rebased to the current public tip.
Can you please rebase to the current tip again? Can't apply as it is now.
https://codereview.adblockplus.org/5187613258416128/diff/29321144/src/plugin/... File src/plugin/PluginDebug.cpp (right): https://codereview.adblockplus.org/5187613258416128/diff/29321144/src/plugin/... src/plugin/PluginDebug.cpp:33: static CComAutoCriticalSection s_criticalSectionDebugLock; What will happen if we remove `s_criticalSectionDebugLock`? https://codereview.adblockplus.org/5187613258416128/diff/29321144/src/plugin/... src/plugin/PluginDebug.cpp:50: class LogText virtual destructor is missed here, the derived classes will leak.
https://codereview.adblockplus.org/5187613258416128/diff/29321144/src/plugin/... File src/plugin/PluginDebug.cpp (right): https://codereview.adblockplus.org/5187613258416128/diff/29321144/src/plugin/... src/plugin/PluginDebug.cpp:33: static CComAutoCriticalSection s_criticalSectionDebugLock; On 2015/10/12 12:46:20, sergei wrote: > What will happen if we remove `s_criticalSectionDebugLock`? The problem right now (and also in the later version with an active queue processing the messages) is that we are writing to log files both (1) directly in-line when called and (2) indirectly through a queue, both in the old version (which is still being used in the code for this patch set) and the new version (subsequent patch set). This semaphore is being used to serialize writing to the log files. If we didn't do that, we could see occasional interleaving of message text when there was a context switch during a file write operation. My plan is to eliminate this class and all of its uses. Once we get logging working through the active queue, we can convert the log messages, of all kinds, to _all_ go through the queue. Once that's done, all the file I/O will be in the worker thread of the active queue. It will be implicitly serialized and there will be no possible race conditions between multiple threads trying to write to log files. This method, in addition, has a performance benefit. Right now, we're using synchronous, blocking disk I/O in all the BHO functions we provide. Getting them out of the execution path will improve call times as IE sees them. Admittedly this mostly applies right now in Debug compiles, and only for trace and debug messages, but there's some monitoring in Release builds we can use this for later where it will matter much more. This change isn't in the present change set, nor then next one, simply to keep the sizes of the change set as small as feasible. https://codereview.adblockplus.org/5187613258416128/diff/29321144/src/plugin/... src/plugin/PluginDebug.cpp:50: class LogText On 2015/10/12 12:46:20, sergei wrote: > virtual destructor is missed here, the derived classes will leak. Yep. I'll add it after I get a rebase posted.
Patch set 6 -- rebase only. No other substantive changes that affect the review Patch set 7 -- Addressed sergei's comment and added virtual destructor to LogText
LGTM with nit addressed. https://codereview.adblockplus.org/5187613258416128/diff/29330365/src/plugin/... File src/plugin/PluginTabBase.cpp (right): https://codereview.adblockplus.org/5187613258416128/diff/29330365/src/plugin/... src/plugin/PluginTabBase.cpp:342: CPluginSettings::GetInstance(); Nit: This is a dummy call now. Note, the comment is misleading. Its here from the old days when we were using the settings.ini for initialization.
https://codereview.adblockplus.org/5187613258416128/diff/29330365/src/plugin/... File src/plugin/PluginTabBase.cpp (right): https://codereview.adblockplus.org/5187613258416128/diff/29330365/src/plugin/... src/plugin/PluginTabBase.cpp:342: CPluginSettings::GetInstance(); On 2015/11/25 04:42:30, Oleksandr wrote: > Nit: This is a dummy call now. Note, the comment is misleading. Its here from > the old days when we were using the settings.ini for initialization. This whole function is going away, including the comment and the dummy call. See the following review: https://codereview.adblockplus.org/29323611/diff/29324420/src/plugin/PluginTa... If we change it here, it just means dealing later with a merge conflict or making new patch sets. Doesn't seem worth it to change here at this point.
New patch set is rebase only after recent public commits.
https://codereview.adblockplus.org/5187613258416128/diff/29321144/src/plugin/... File src/plugin/PluginDebug.cpp (right): https://codereview.adblockplus.org/5187613258416128/diff/29321144/src/plugin/... src/plugin/PluginDebug.cpp:33: static CComAutoCriticalSection s_criticalSectionDebugLock; On 2015/10/13 17:33:19, Eric wrote: > On 2015/10/12 12:46:20, sergei wrote: > > What will happen if we remove `s_criticalSectionDebugLock`? > > The problem right now (and also in the later version with an active queue > processing the messages) is that we are writing to log files both (1) directly > in-line when called and (2) indirectly through a queue, both in the old version > (which is still being used in the code for this patch set) and the new version > (subsequent patch set). This semaphore is being used to serialize writing to the > log files. If we didn't do that, we could see occasional interleaving of message > text when there was a context switch during a file write operation. > > My plan is to eliminate this class and all of its uses. Once we get logging > working through the active queue, we can convert the log messages, of all kinds, > to _all_ go through the queue. Once that's done, all the file I/O will be in the > worker thread of the active queue. It will be implicitly serialized and there > will be no possible race conditions between multiple threads trying to write to > log files. > > This method, in addition, has a performance benefit. Right now, we're using > synchronous, blocking disk I/O in all the BHO functions we provide. Getting them > out of the execution path will improve call times as IE sees them. Admittedly > this mostly applies right now in Debug compiles, and only for trace and debug > messages, but there's some monitoring in Release builds we can use this for > later where it will matter much more. > > This change isn't in the present change set, nor then next one, simply to keep > the sizes of the change set as small as feasible. The plan is clear but the reason we need `s_criticalSectionDebugLock` is not clear. I think we can safely get rid of it. It's used only inside `CPluginDebugLock` which firstly obtains a lock using named mutex (`CPluginMutex`) and then it calls `s_criticalSectionDebugLock.Lock()`. In the destructor it calls firstly `s_criticalSectionDebugLock.Unlock();` and then releases `CPluginMutex`. `s_criticalSectionDebugLock.Lock()` does not ever wait thus does not serialize an access to anything. https://codereview.adblockplus.org/5187613258416128/diff/29331020/src/plugin/... File src/plugin/PluginDebug.cpp (right): https://codereview.adblockplus.org/5187613258416128/diff/29331020/src/plugin/... src/plugin/PluginDebug.cpp:72: virtual std::string Text() const override I would propose to omit `virtual` when we use `override` and always use `override` to re-/implement any virtual method.
https://codereview.adblockplus.org/5187613258416128/diff/29321144/src/plugin/... File src/plugin/PluginDebug.cpp (right): https://codereview.adblockplus.org/5187613258416128/diff/29321144/src/plugin/... src/plugin/PluginDebug.cpp:33: static CComAutoCriticalSection s_criticalSectionDebugLock; There's only one occurrence of 'CPluginDebugLock', but it's a sentry object in 'Write()' below. As a sentry object, it calls the constructor at the point of declaration. It calls the destructor at the end of the body of 'Write()' when it goes out of scope. The critical section will lock if there's another thread currently in a call to 'Write()'. We can't get rid of the 's_criticalSectionDebugLock' until we don't need that sentry object any more, that is, until after all the calls to 'Write()' occur in a single thread. At that point 'CPluginDebugLock' can go away along with all it entrains. https://codereview.adblockplus.org/5187613258416128/diff/29321144/src/plugin/... src/plugin/PluginDebug.cpp:161: CPluginDebugLock lock; This is the sentry object. 'Write()' is currently called from multiple threads. https://codereview.adblockplus.org/5187613258416128/diff/29331020/src/plugin/... File src/plugin/PluginDebug.cpp (right): https://codereview.adblockplus.org/5187613258416128/diff/29331020/src/plugin/... src/plugin/PluginDebug.cpp:72: virtual std::string Text() const override On 2015/11/30 14:15:03, sergei wrote: > I would propose to omit `virtual` when we use `override` and always use > `override` to re-/implement any virtual method. It's good to have both in place. Makes the intent crystal clear.
https://codereview.adblockplus.org/5187613258416128/diff/29321144/src/plugin/... File src/plugin/PluginDebug.cpp (right): https://codereview.adblockplus.org/5187613258416128/diff/29321144/src/plugin/... src/plugin/PluginDebug.cpp:33: static CComAutoCriticalSection s_criticalSectionDebugLock; On 2015/11/30 17:39:01, Eric wrote: > There's only one occurrence of 'CPluginDebugLock', but it's a sentry object in > 'Write()' below. As a sentry object, it calls the constructor at the point of > declaration. It calls the destructor at the end of the body of 'Write()' when it > goes out of scope. The critical section will lock if there's another thread > currently in a call to 'Write()'. > > We can't get rid of the 's_criticalSectionDebugLock' until we don't need that > sentry object any more, that is, until after all the calls to 'Write()' occur in > a single thread. At that point 'CPluginDebugLock' can go away along with all it > entrains. > There is already CPluginMutex and it serializes the access to the file system-wise, it does not matter whether Write is called from different threads of one process of of many processes, the access is serialized by CPluginMutex. s_criticalSectionDebugLock does not wait for anything. https://codereview.adblockplus.org/5187613258416128/diff/29331020/src/plugin/... File src/plugin/PluginDebug.cpp (right): https://codereview.adblockplus.org/5187613258416128/diff/29331020/src/plugin/... src/plugin/PluginDebug.cpp:72: virtual std::string Text() const override On 2015/11/30 17:39:01, Eric wrote: > On 2015/11/30 14:15:03, sergei wrote: > > I would propose to omit `virtual` when we use `override` and always use > > `override` to re-/implement any virtual method. > > It's good to have both in place. Makes the intent crystal clear. Actually, I would like to note that it's not related to this issue, we can discuss it somewhere else, I merely wanted to attract the attention. `virtual` was very useful until introduction of `override`, now it merely increases the line width because `override` cannot be used for non-virtual methods.
https://codereview.adblockplus.org/5187613258416128/diff/29321144/src/plugin/... File src/plugin/PluginDebug.cpp (right): https://codereview.adblockplus.org/5187613258416128/diff/29321144/src/plugin/... src/plugin/PluginDebug.cpp:33: static CComAutoCriticalSection s_criticalSectionDebugLock; On 2015/11/30 18:14:29, sergei wrote: > There is already CPluginMutex and it serializes the access to the file > system-wise Now I see what you're getting at. Yes, the critical section is redundant. Removing it though, would be out of scope for this change set. This is, notionally, about removing CString, although I did that by reworking the string handling wholesale. CPluginDebugLock is unaltered from the previous version except for reformatting. The next change set, already up for review, reworks the threading etc. and would be the right place to make this change. Please remind me again there if I forget. https://codereview.adblockplus.org/5187613258416128/diff/29331020/src/plugin/... File src/plugin/PluginDebug.cpp (right): https://codereview.adblockplus.org/5187613258416128/diff/29331020/src/plugin/... src/plugin/PluginDebug.cpp:72: virtual std::string Text() const override On 2015/11/30 18:14:29, sergei wrote: > Actually, I would like to note that it's not related to this issue, we can > discuss it somewhere else OK.
https://codereview.adblockplus.org/5187613258416128/diff/29321144/src/plugin/... File src/plugin/PluginDebug.cpp (right): https://codereview.adblockplus.org/5187613258416128/diff/29321144/src/plugin/... src/plugin/PluginDebug.cpp:33: static CComAutoCriticalSection s_criticalSectionDebugLock; On 2015/12/01 20:43:57, Eric wrote: > On 2015/11/30 18:14:29, sergei wrote: > > There is already CPluginMutex and it serializes the access to the file > > system-wise > > Now I see what you're getting at. Yes, the critical section is redundant. > > Removing it though, would be out of scope for this change set. This is, > notionally, about removing CString, although I did that by reworking the string > handling wholesale. CPluginDebugLock is unaltered from the previous version > except for reformatting. The next change set, already up for review, reworks the > threading etc. and would be the right place to make this change. Please remind > me again there if I forget. Acknowledged. https://codereview.adblockplus.org/5187613258416128/diff/29331020/src/plugin/... File src/plugin/PluginDebug.cpp (right): https://codereview.adblockplus.org/5187613258416128/diff/29331020/src/plugin/... src/plugin/PluginDebug.cpp:57: class LogTextFixed What about naming of classes differently? Let's add specialization of the class for the derived extending class before the name of the base class. DerivedClass->Class. For example, base class: class Text{}; // other name examples are like "Exception", "Tool", "Filter", etc and derived class: class FixedText: public Text{}; // "FileNotFoundException", "OutOfMemoryException", "LogTool", "FileTool", "BlockingFilter", "ExceptionFilter". Pay attention that it's clear that "FilterException" is an exception and "ExceptionFilter" is a filter. Depending on the domain "ExceptionFilter" can be also a part of "Exception", it still works. And for components (parts) of the class let's add the name of the part at the end of the class name. Class, ClassPart. For example, class Exception;// consists from some parts. Another example is "Filter". The possible components of "Exception" class can be for example, "ExceptionMessage", "ExceptionLocation", any "ExceptionPart". For `Filter` - 'FilterRule", "FilterName", "FilterAuthor". More complex example, compare the sounding of "ExceptionFilterType" and "TypeFilterException". So, according to the rules above, `LogTextFixed` should be named as `FixedLogText`. https://codereview.adblockplus.org/5187613258416128/diff/29331020/src/plugin/... src/plugin/PluginDebug.cpp:113: const std::unique_ptr<LogText> text; Just in case, what is the reason of extensively putting const for member types? In this particular case only std::unique_ptr is "constant" but we are still allowed to call non-const methods of `LogText`, although there is no any one. https://codereview.adblockplus.org/5187613258416128/diff/29331020/src/plugin/... src/plugin/PluginDebug.cpp:190: out.open(logFileName, std::ios::app); I wonder whether we need a synchronization here. Even later with a logging thread which can keep the file opened all the time, how reliable does opening/creating of the file from multiple processes work?
https://codereview.adblockplus.org/5187613258416128/diff/29331020/src/plugin/... File src/plugin/PluginDebug.cpp (right): https://codereview.adblockplus.org/5187613258416128/diff/29331020/src/plugin/... src/plugin/PluginDebug.cpp:57: class LogTextFixed On 2015/12/02 13:53:00, sergei wrote: > What about naming of classes differently? No. Naming the subclasses of 'class LogText' with the prefix "LogText" means that they all appear adjacently in documentation and class browsers, which present names in lexicographic order. This is quite useful in situations like the present case where there's lots of small variation on a basic theme. Ordinarily you don't include the base class name at all and use a more descriptive name. If you feel a need to include the base class name in a subclass name, the base name should go at the beginning. As for prefixing members with the class name, that's a technique required for primitive languages without proper support for scoped names. In C++, we can say "classname::member" or "classname.member" (depending on context) if we want name-appending behavior. https://codereview.adblockplus.org/5187613258416128/diff/29331020/src/plugin/... src/plugin/PluginDebug.cpp:113: const std::unique_ptr<LogText> text; On 2015/12/02 13:53:00, sergei wrote: > Just in case, what is the reason of extensively putting const for member types? 'const' members mean "initialized only at construction time". I use it to get compiler assistance to prevent accidental modification of the member. 'LogEntry' would like to be a POD (plain old data) type, but because the data has to vary, it can't be. There's not particularly great support for variant types in C++ (unlike, say, Ada95), so we do with polymorphism. > In this particular case only std::unique_ptr is "constant" but we are still > allowed to call non-const methods of `LogText`, although there is no any one. FYI. Apropos the present case for 'LogEntry::text', I drop the 'const' declaration on this member in the next change set. It interfered with writing a move constructor. Arguably this is a deficiency in C++, since 'const' means "constant for the scope beginning after member initialization and ending at the return of the destructor" rather than "constant for the scope beginning after the return of the constructor and before the execution of the destructor". There's no way of expressing the latter notion. The 'const' declaration, though, works for the present change set. No need to change it here. https://codereview.adblockplus.org/5187613258416128/diff/29331020/src/plugin/... src/plugin/PluginDebug.cpp:190: out.open(logFileName, std::ios::app); On 2015/12/02 13:53:00, sergei wrote: > I wonder whether we need a synchronization here. Even later with a logging > thread which can keep the file opened all the time, how reliable does > opening/creating of the file from multiple processes work? Easy answer: This locking behavior is the same as it was before and as it has been for the last few years. We seem to have had no trouble with it so far. Behavior as-used answer: This code executes immediately upon construction of the first BHO object, since there's a log message there. There seems to be enough time delay in construction of the second BHO object for the file operation to complete before a possible race. Documentation-based answer: I believe that file open/create operations are atomic on local Windows file systems. I could be mistaken on that, though, and I haven't dug through documentation to find out. It's conceivable that this might fail if ABP is installed on a network drive. Message to developers: Don't do that. In other words, if it fails, it doesn't matter if no one's looking at the logs. Immediate answer: Regardless of any of the above, it's out of scope at present as another candidate synchronization change.
It's been almost two weeks since the last action on this review. The only code suggestion from last time was to rename some variables, which I rejected. It doesn't seem like there are any more substantive issues to be raised here. If there's anything new at this point, there's an immediately following review we can put them in. It's now been nine months since I first started this review. There's another substantive change after this one that's been in the queue for four month now. Can we please move on?
@sergei, it's now been almost three weeks since any action on this. I sent out a reminder last week as well. What's the delay?
On 2015/12/22 12:52:40, Eric wrote: > @sergei, it's now been almost three weeks since any action on this. I sent out a > reminder last week as well. > > What's the delay? I'm waiting for the opinion of others regarding class naming. FYI, we are actually already using proposed naming policy, take a look at CFilterElementHideAttrSelector, CPluginFilter, CPluginMutex, CPluginSettings, CPluginUserSettings (it's not something containing `SettingsUser` like `TextFixed`) and we are also working with it, e.g. ATL::CComPtr, IHTMLElement, IHTMLElementCollection and so on.
On 2015/12/22 14:27:07, sergei wrote:
> I'm waiting for the opinion of others regarding class naming.
You should have said that three weeks ago in response to my rejection of your
naming suggestions. Remaining silent when you think you're asking for something
is a sure way to damage the development process. Please don't do this in the
future.
Just to make sure you're not holding back any thing else, is naming the only
remaining objection here?
> FYI, we are actually already using proposed naming policy, take a look at
> CFilterElementHideAttrSelector, CPluginFilter, CPluginMutex, CPluginSettings,
From the ABP Coding Style document:
https://adblockplus.org/en/coding-style
| No hungarian notation, no special variable name prefixes or suffixes
| denoting type or scope. All variable names start with a lower case letter.
All these initial "C", "m_", "s_" prefixes are legacy hold-overs from the old
code base. New code should not use them.
On 2015/12/22 14:46:19, Eric wrote: > On 2015/12/22 14:27:07, sergei wrote: > > I'm waiting for the opinion of others regarding class naming. > > You should have said that three weeks ago in response to my rejection of your > naming suggestions. Remaining silent when you think you're asking for something > is a sure way to damage the development process. Please don't do this in the > future. OK but I'm pretty sure that everybody should participate in the review without addition invitation. > Just to make sure you're not holding back any thing else, is naming the only > remaining objection here? I think so. > > > FYI, we are actually already using proposed naming policy, take a look at > > CFilterElementHideAttrSelector, CPluginFilter, CPluginMutex, CPluginSettings, > > From the ABP Coding Style document: > https://adblockplus.org/en/coding-style > | No hungarian notation, no special variable name prefixes or suffixes > | denoting type or scope. All variable names start with a lower case letter. > > All these initial "C", "m_", "s_" prefixes are legacy hold-overs from the old > code base. New code should not use them. Please don't mix the order of words in the names with Hungarian notation and the prefixes. And just in case to avoid unnecessary work, I don't think that prefixes should go away, fortunately, https://developer.mozilla.org/en-US/docs/Mozilla/Developer_guide/Coding_Style... supports me, however I would like to use "m_" (only for class members, not for struct members), "s_" for global static variables and for members (ideally there should not be static members), "g_" for global variables and "kSomeGlobalConstant". If you want to discuss it, it's better to do it not in the review.
On 2015/12/22 15:56:58, sergei wrote:
> OK but I'm pretty sure that everybody should participate in the review without
> addition invitation.
Oleksandr signed off on this a month ago. There haven't been any substantive
changes since. I certainly don't expect him to be paying close attention at this
point.
> > All these initial "C", "m_", "s_" prefixes are legacy hold-overs from the
old
> > code base. New code should not use them.
> Please don't mix the order of words in the names with Hungarian notation and
the
> prefixes.
If you insist on continuing to discuss the materials of the bike shed, I'll
refer you to this document again:
https://en.wikipedia.org/wiki/Parkinson's_law_of_triviality
My point is that you're claiming we should be consistent with names, beginning
with "C" in this case, that already don't adhere to published style guidance.
It's not a strong argument.
> go away, fortunately,
>
https://developer.mozilla.org/en-US/docs/Mozilla/Developer_guide/Coding_Style...
> supports me
Unfortunately, it does not. The style document explicitly states not to use
Hungarian etc. notations. It incorporates by reference a document that conflicts
with this advice. Where there is a conflict, the explicit statement overrides
the included document.
The reasoning behind not using Hungarian notation was that we should not aim to have variable names that are reflecting variable type, its position in code or scope because those can change quite easily, and in general we want to be as flexible as possible. In this spirit, I think we should definitely not have class members with "classPart" names. As for class names I feel like this is merely a matter of taste, however I personally like LogTextFixed more. A similar naming scheme is used quite often in our code already (for example the CInternetProtocolXXX stuff in APP or CPluginTab naming).
LGTM 
|
||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
