Enhance logging in order to help diagnose in-the-field issues. cf: rdar://problem/23836456 rdar://problem/22870338
Created attachment 271438 [details] Patch
Created attachment 271684 [details] Patch
Attachment 271684 [details] did not pass style-queue: ERROR: Source/WTF/wtf/Assertions.h:458: Multi line control clauses should use braces. [whitespace/braces] [4] ERROR: Source/WTF/wtf/Assertions.h:464: Multi line control clauses should use braces. [whitespace/braces] [4] Total errors found: 2 in 71 files If any of these errors are false positives, please file a bug against check-webkit-style.
Created attachment 271712 [details] Patch
Attachment 271712 [details] did not pass style-queue: ERROR: Source/WTF/wtf/Assertions.h:458: Multi line control clauses should use braces. [whitespace/braces] [4] ERROR: Source/WTF/wtf/Assertions.h:464: Multi line control clauses should use braces. [whitespace/braces] [4] Total errors found: 2 in 71 files If any of these errors are false positives, please file a bug against check-webkit-style.
Comment on attachment 271712 [details] Patch View in context: https://bugs.webkit.org/attachment.cgi?id=271712&action=review Some initial comments. I'll review more deeply later. > Source/WTF/ChangeLog:12 > + Always-on logging is implemented in the form of some new macros. Please don't duplicate the changelog entries. they should refer to specific project changes. > Source/WTF/wtf/Assertions.cpp:503 > + ASSERT(timer); We normally don't take raw pointers in if they are expected to be non-null. This probably should take a WTFTimer& instead. > Source/WTF/wtf/Assertions.cpp:510 > +bool WTFTimerExceededThreshold(WTFTimer* timer) We normally don't take raw pointers in if they are expected to be non-null. This probably should take a WTFTimer& instead. > Source/WTF/wtf/Assertions.cpp:513 > + if (timer->m_end < 0.0) { Seems kind of unexpected that this function (given its name) would update timer->m_end, isn't it? > Source/WTF/wtf/Assertions.cpp:520 > +bool WTFIsSimpleFormat(const char* format) Can you document with a comment what a "simple" format is? > Source/WTF/wtf/Assertions.h:43 > +#if USE(OS_LOG) The ifdefed includes should come after the regular includes, not in the middle of other includes. > Source/WTF/wtf/Assertions.h:139 > +typedef struct { isn't the typedef struct a C thing? > Source/WTF/wtf/Assertions.h:168 > +WTF_EXPORT_PRIVATE void WTFTimerInit(WTFTimer*, double threshold); We try to use std:chrono these days instead of double to represent times or durations. > Source/WebCore/html/parser/HTMLDocumentParser.cpp:252 > + LOG_ALWAYS_TIMER_START(pumpTimer, 0.100); this 0.100 is not very readable. This is why we use std::chrono for these things. Also, for theses things we tend to use scope and local variables with "Scope" in the name. e.g. { LogIfSlowerThan logger("blah blah", 100_ms); // ... } > Tools/TestWebKitAPI/Tests/WTF/Assertions.cpp:35 > +// <samples> * (<samples> + 1), we end up with 146,325,312 tests. If we were to This seems like a lot. How long does it take to run all these tests. I am working about the extra testing time on the slower bots and possible timeouts.
(In reply to comment #6) > Comment on attachment 271712 [details] > Patch > > View in context: > https://bugs.webkit.org/attachment.cgi?id=271712&action=review > > Some initial comments. I'll review more deeply later. > > > Source/WTF/ChangeLog:12 > > + Always-on logging is implemented in the form of some new macros. > > Please don't duplicate the changelog entries. they should refer to specific > project changes. OK. I'll rewrite the changelog entries. > > Source/WTF/wtf/Assertions.cpp:503 > > + ASSERT(timer); > > We normally don't take raw pointers in if they are expected to be non-null. > This probably should take a WTFTimer& instead. There's a comment in Assertions.h saying that the file should be compatible with C. That's why this whole timing facility uses pointers, "typedef struct", and non-member functions. However, as we discussed offline, the utility of the timing functions is questionable, so I'll be taking those out for this check-in. > > Source/WTF/wtf/Assertions.cpp:510 > > +bool WTFTimerExceededThreshold(WTFTimer* timer) > > We normally don't take raw pointers in if they are expected to be non-null. > This probably should take a WTFTimer& instead. > > > Source/WTF/wtf/Assertions.cpp:513 > > + if (timer->m_end < 0.0) { > > Seems kind of unexpected that this function (given its name) would update > timer->m_end, isn't it? Taking this out, per above. > > Source/WTF/wtf/Assertions.cpp:520 > > +bool WTFIsSimpleFormat(const char* format) > > Can you document with a comment what a "simple" format is? OK. > > Source/WTF/wtf/Assertions.h:43 > > +#if USE(OS_LOG) > > The ifdefed includes should come after the regular includes, not in the > middle of other includes. OK. > > Source/WTF/wtf/Assertions.h:139 > > +typedef struct { > > isn't the typedef struct a C thing? Yes, per above. Also, taking out per above. > > Source/WTF/wtf/Assertions.h:168 > > +WTF_EXPORT_PRIVATE void WTFTimerInit(WTFTimer*, double threshold); > > We try to use std:chrono these days instead of double to represent times or > durations. OK. But taking this out, per above. > > Source/WebCore/html/parser/HTMLDocumentParser.cpp:252 > > + LOG_ALWAYS_TIMER_START(pumpTimer, 0.100); > > this 0.100 is not very readable. This is why we use std::chrono for these > things. OK. But taking this out, per above. > Also, for theses things we tend to use scope and local variables with > "Scope" in the name. e.g. > { > LogIfSlowerThan logger("blah blah", 100_ms); > // ... > } OK. But taking this out, per above. > > Tools/TestWebKitAPI/Tests/WTF/Assertions.cpp:35 > > +// <samples> * (<samples> + 1), we end up with 146,325,312 tests. If we were to > > This seems like a lot. How long does it take to run all these tests. I am > working about the extra testing time on the slower bots and possible > timeouts. I've toned this down to about 180,000 tests, or about 1% of what it used to be. The tests used to take about 120 second to run, so we should be running in 1-2 seconds now.
Comment on attachment 271712 [details] Patch View in context: https://bugs.webkit.org/attachment.cgi?id=271712&action=review > Source/WebKit2/NetworkProcess/NetworkProcess.cpp:128 > +#if !LOG_ALWAYS_DISABLED > + reportResourceUsage(); > +#endif It seems like it would be better to have this called by the callers of didReceiveMessage, since there are fewer of those. > Source/WebKit2/Platform/IPC/Connection.h:102 > +#if !LOG_ALWAYS_DISABLED > + void reportResourceUsage(); > + > + private: > + double m_lastReportTime = 0; > + struct rusage m_usage = {{0, 0}, {0, 0}, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0}; > +#endif It seems really odd for this to be on the client. Client's usually are just used for delegation and notification. It seems like this should be on the Connection itself and probably abstracted out a bit. Also, it should be using std::chrono instead of doubles.
Thanks, Sam. I'll look at refactoring.
The content of attachment 271438 [details] has been deleted by Lucas Forschler <lforschler@apple.com> who provided the following reason: yes The token used to delete this attachment was generated at 2016-02-24 16:51:00 PST.
The content of attachment 271712 [details] has been deleted by Lucas Forschler <lforschler@apple.com> who provided the following reason: yes The token used to delete this attachment was generated at 2016-02-24 16:51:20 PST.
The content of attachment 271684 [details] has been deleted by Lucas Forschler <lforschler@apple.com> who provided the following reason: yes The token used to delete this attachment was generated at 2016-02-24 16:51:52 PST.
I don't remember what this was about. I don't have any local work towards this.