|
|
Created:
4 years, 6 months ago by xidachen Modified:
4 years, 5 months ago CC:
chromium-reviews, dshwang, ajuma+watch-canvas_chromium.org, blink-reviews-html_chromium.org, dglazkov+blink, Rik, asvitkine+watch_chromium.org, blink-reviews Base URL:
https://chromium.googlesource.com/chromium/src.git@master Target Ref:
refs/pending/heads/master Project:
chromium Visibility:
Public. |
DescriptionTrack performance of toBlob and its complete timeout delay
This CL does two things:
1. Track the performance of a toBlob API call. Because toBlob has a call
back, so we put a timer in the CanvasAsyncToBlob class.
2. Track how often the complete timeout delay happens in toBlob calls.
BUG=612585, 608815
Committed: https://crrev.com/8c59e014125ad442b32c21b1724add603b489cc2
Cr-Commit-Position: refs/heads/master@{#403362}
Patch Set 1 #Patch Set 2 : change to thread safe static local histogram #
Total comments: 2
Patch Set 3 : address comments #Patch Set 4 : clean up code #Patch Set 5 : add timing for start&complete timeout #Patch Set 6 : add to histograms #Patch Set 7 : better categorization #
Total comments: 11
Patch Set 8 : address comments #Patch Set 9 : minor clean up #
Total comments: 3
Patch Set 10 : need to see diff, DO NOT COMMIT this PS #Patch Set 11 : need to see diff #Patch Set 12 : rebase #
Total comments: 10
Patch Set 13 : address comments #
Total comments: 4
Patch Set 14 : correctly accumulate idle time slices #
Total comments: 10
Patch Set 15 : address comments #
Total comments: 4
Patch Set 16 : address comments #
Total comments: 2
Patch Set 17 : add a NotUsed enum #
Total comments: 17
Patch Set 18 : more comments #
Total comments: 5
Patch Set 19 : changed description #
Total comments: 2
Patch Set 20 : nits #Patch Set 21 : fix compile error #
Messages
Total messages: 46 (9 generated)
xidachen@chromium.org changed reviewers: + isherman@chromium.org, junov@chromium.org, xlai@chromium.org
xlai@: could you please make sure that I place the enum histogram and the timer in the right place?
https://codereview.chromium.org/2039673002/diff/20001/third_party/WebKit/Sour... File third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp (right): https://codereview.chromium.org/2039673002/diff/20001/third_party/WebKit/Sour... third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp:294: recordElapsedTime(); The failure case should not be recording to the same timing metrics as the success case. We could probably do without capturing time for the failure cases. However, it would be relevant to have a fail vs. succeed histogram for each mime type. https://codereview.chromium.org/2039673002/diff/20001/third_party/WebKit/Sour... third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp:369: DEFINE_THREAD_SAFE_STATIC_LOCAL(EnumerationHistogram, idleTaskCompleteTimeoutDelayHistogram, new EnumerationHistogram("Canvas.ToBlob.IdleTaskCompleteTimeoutDelay", NumberOfMimeTypeSupported)); This histogram does not provide very significant info on its own. It would be better to have a separate histogram per mime type, and for each such histogram, the bins should be idleTaskTimeout vs. idleTaskCompleted. That way we get histograms that tell us the fraction of tasks that timed-out, which is directly relevant data. Also, the word "Delay" is not very relevant here.
PTAL Right now we are measuring 3 things: 1. Duration of a toBlob API call. 2. Frequency of occurrence of start & complete timeout event. 4 histograms (PNG, JPEG, WEBP, Unknown), and each one has 2 bins (start, complete). 3. Duration of each timeout event. Similar to the above, 4 histograms and each has 2 bins.
Hi Xida, as a summary, for the three things that you're measuring: 1. Duration of a toBlob API call --> Please remove measuring the duration of a failed call for different mime type; we might be interested to know that something fails but we're not interested to know how long it fails for different mine type. --> Also the beginning of the duration measurement is not right. 2. Frequency of occurrence of start & complete timeout event. 4 histograms (PNG, JPEG, WEBP, Unknown), and each one has 2 bins (start, complete). --> I think the histogram you're adding for this part is unnecessary. For *ALL* toBlob calls that have idle task supported, start timeout event is always posted and complete timeout event is also often posted. What's the purpose of recording that these two timeout events happen? --> In fact, I think a more meaningful measurement should be recording down when a "switch" from idle to non-idle happens. And I believe that's what Issue 608815 intends to do. 3. Duration of each timeout event. Similar to the above, 4 histograms and each has 2 bins. --> I don't think we need to have "unknown" bin. It was ASSERT_NOT_REACHED() from the very beginning. https://codereview.chromium.org/2039673002/diff/120001/third_party/WebKit/Sou... File third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp (right): https://codereview.chromium.org/2039673002/diff/120001/third_party/WebKit/Sou... third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp:98: m_startTime = WTF::monotonicallyIncreasingTime(); To measure the total elapsed time of toBlob API call, I find it odd to start the measurement from here. The CanvasAsyncBlobCreator is created in the *middle* of the toBlob API call. You should start the timer from the beginning of HTMLCanvasElement::toBlob(). https://codereview.chromium.org/2039673002/diff/120001/third_party/WebKit/Sou... third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp:277: DEFINE_THREAD_SAFE_STATIC_LOCAL(CustomCountHistogram, toBlobUnknownCounter, new CustomCountHistogram("Blink.Canvas.ToBlob.Unknown.Succeed", 0, 10000000, 50)); "Unknown" type is impossible to reach here. See "ASSERT_NOT_REACH()" in above code. https://codereview.chromium.org/2039673002/diff/120001/third_party/WebKit/Sou... third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp:292: DEFINE_THREAD_SAFE_STATIC_LOCAL(CustomCountHistogram, toBlobPNGCounter, new CustomCountHistogram("Blink.Canvas.ToBlob.PNG.Failed", 0, 10000000, 50)); I sincerely feels that such a detailed histogram for "Failed" use case is unnecessary. I don't really think we're interested to know how long it takes to fail. https://codereview.chromium.org/2039673002/diff/120001/third_party/WebKit/Sou... third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp:342: DEFINE_THREAD_SAFE_STATIC_LOCAL(EnumerationHistogram, idleTaskTimeoutEventPNG, new EnumerationHistogram("Canvas.ToBlob.IdleTaskTimeout.PNG", IdleTaskTimeoutSupported)); What is the purpose of this histogram? https://codereview.chromium.org/2039673002/diff/120001/third_party/WebKit/Sou... third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp:370: DEFINE_THREAD_SAFE_STATIC_LOCAL(CustomCountHistogram, toBlobUnknownStartTimeoutCounter, new CustomCountHistogram("Blink.Canvas.ToBlobTimeoutDuration.Unknown.Start", 0, 10000000, 50)); Same comment for "unknown".
xlai@: I believe I have addressed all comments. PTAL https://codereview.chromium.org/2039673002/diff/120001/third_party/WebKit/Sou... File third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp (right): https://codereview.chromium.org/2039673002/diff/120001/third_party/WebKit/Sou... third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp:98: m_startTime = WTF::monotonicallyIncreasingTime(); On 2016/06/07 16:08:14, xlai (Olivia) wrote: > To measure the total elapsed time of toBlob API call, I find it odd to start the > measurement from here. The CanvasAsyncBlobCreator is created in the *middle* of > the toBlob API call. You should start the timer from the beginning of > HTMLCanvasElement::toBlob(). Yes, that makes total sense. I place the start after checking originClean() and isPaintable(). https://codereview.chromium.org/2039673002/diff/120001/third_party/WebKit/Sou... third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp:277: DEFINE_THREAD_SAFE_STATIC_LOCAL(CustomCountHistogram, toBlobUnknownCounter, new CustomCountHistogram("Blink.Canvas.ToBlob.Unknown.Succeed", 0, 10000000, 50)); On 2016/06/07 16:08:14, xlai (Olivia) wrote: > "Unknown" type is impossible to reach here. See "ASSERT_NOT_REACH()" in above > code. Done. https://codereview.chromium.org/2039673002/diff/120001/third_party/WebKit/Sou... third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp:292: DEFINE_THREAD_SAFE_STATIC_LOCAL(CustomCountHistogram, toBlobPNGCounter, new CustomCountHistogram("Blink.Canvas.ToBlob.PNG.Failed", 0, 10000000, 50)); On 2016/06/07 16:08:14, xlai (Olivia) wrote: > I sincerely feels that such a detailed histogram for "Failed" use case is > unnecessary. I don't really think we're interested to know how long it takes to > fail. Done. https://codereview.chromium.org/2039673002/diff/120001/third_party/WebKit/Sou... third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp:342: DEFINE_THREAD_SAFE_STATIC_LOCAL(EnumerationHistogram, idleTaskTimeoutEventPNG, new EnumerationHistogram("Canvas.ToBlob.IdleTaskTimeout.PNG", IdleTaskTimeoutSupported)); On 2016/06/07 16:08:14, xlai (Olivia) wrote: > What is the purpose of this histogram? Change this to record the occurrence of switch from idle to main thread. https://codereview.chromium.org/2039673002/diff/120001/third_party/WebKit/Sou... third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp:370: DEFINE_THREAD_SAFE_STATIC_LOCAL(CustomCountHistogram, toBlobUnknownStartTimeoutCounter, new CustomCountHistogram("Blink.Canvas.ToBlobTimeoutDuration.Unknown.Start", 0, 10000000, 50)); On 2016/06/07 16:08:14, xlai (Olivia) wrote: > Same comment for "unknown". Done. https://codereview.chromium.org/2039673002/diff/160001/third_party/WebKit/Sou... File third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp (right): https://codereview.chromium.org/2039673002/diff/160001/third_party/WebKit/Sou... third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp:345: } Is this recording meaningful now that we change to record how many times it switch from idle to main thread?
https://codereview.chromium.org/2039673002/diff/120001/tools/metrics/histogra... File tools/metrics/histograms/histograms.xml (right): https://codereview.chromium.org/2039673002/diff/120001/tools/metrics/histogra... tools/metrics/histograms/histograms.xml:3482: + <owner>junov@chromium.org</owner> You can put more that one owner, you know? Please put xlai and myself on all of these histograms. https://codereview.chromium.org/2039673002/diff/160001/third_party/WebKit/Sou... File third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.h (right): https://codereview.chromium.org/2039673002/diff/160001/third_party/WebKit/Sou... third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.h:39: enum IdleTaskTimeoutType { I find these enum names a bit hard to interpret. We have basically four categories of outcome: Failed, completed before idle task timeout, completed after idle task timeout, completed without using idle scheduling (for webp). each call to toBlob should add a count to exactly one of these bins. "Failed" could be expanded into more bins if we want to identify failure types.
I've been hanging back while you figure out exactly what histograms you'd like to log, but I do have one quick comment right now: https://codereview.chromium.org/2039673002/diff/160001/tools/metrics/histogra... File tools/metrics/histograms/histograms.xml (right): https://codereview.chromium.org/2039673002/diff/160001/tools/metrics/histogra... tools/metrics/histograms/histograms.xml:91905: + <suffix name="Complete"/> I don't understand what it means to start vs. complete a timeout. If this is an important distinction to measure, could you please clarify within the description text in this file what each of these cases means?
PTAL. So we are recording a few things: 1. The time spent on an entire toBlob API calls. 2. Elapsed time starting from scheduleInitiateEncoding to the actual start of initiateEncoding. 3. Elapsed time from start of idleEncode to the point when idle encode is done. 4. Types of toBlob outcome: Failed, IdleNotSupported (webp), SwitchedToMain, Completed (without switching to main).
Besides the in-line comments below, I have two high-level comments: 1. I don't think you need to use thread safe histogram. Although webp encoding is carried out on non-main thread (which is the only non-main-thread operation in the entire toBlob thing), the recording point (i.e createBlob or createNull) is always happening on main thread. 2. I have a feeling that the enum histogram is not coded correctly here. It seems to me that the patch mistakes between "suffix" and enum type themselves. Could you double check with the documentation in //src/tools/metrics/histograms/histograms.xml? https://codereview.chromium.org/2039673002/diff/220001/third_party/WebKit/Sou... File third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp (right): https://codereview.chromium.org/2039673002/diff/220001/third_party/WebKit/Sou... third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp:207: toBlobPNGIdleEncodeCounter.count(elapsedTime * 1000000.0); Move this whole block of code before this if-else block. https://codereview.chromium.org/2039673002/diff/220001/third_party/WebKit/Sou... third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp:227: toBlobJPEGIdleEncodeCounter.count(elapsedTime * 1000000.0); Move this whole block of code before this if-else block. https://codereview.chromium.org/2039673002/diff/220001/third_party/WebKit/Sou... third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp:277: DEFINE_THREAD_SAFE_STATIC_LOCAL(EnumerationHistogram, toBlobIdleSwitchedToMain, new EnumerationHistogram("Blink.Canvas.ToBlob.IdleTask.SwitchedToMain", IdleTaskNotSupported)); The enum type "SwitchedToMain" is misleading. We are always on main thread. Change the name to "IdleTaskSwitchedToMainThreadTask". Also change the other names to look exactly same as the enum types in m_idleTaskStatus.
https://codereview.chromium.org/2039673002/diff/220001/third_party/WebKit/Sou... File third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp (right): https://codereview.chromium.org/2039673002/diff/220001/third_party/WebKit/Sou... third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp:206: DEFINE_THREAD_SAFE_STATIC_LOCAL(CustomCountHistogram, toBlobPNGIdleEncodeCounter, new CustomCountHistogram("Blink.Canvas.ToBlob.IdleEncodeDuration.PNG", 0, 10000000, 50)); This stat is not very useful the way it is currently computed. What we call an "encode duration" should probably be the *sum* of the time spent in this function for a given encode task. https://codereview.chromium.org/2039673002/diff/220001/third_party/WebKit/Sou... third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp:207: toBlobPNGIdleEncodeCounter.count(elapsedTime * 1000000.0); On 2016/06/13 20:15:06, xlai (Olivia) wrote: > Move this whole block of code before this if-else block. actually, I was think more like doing "m_elapsedTime += ..." in the "if" part, and recording the histogram in the "else" part. Same thing for JPEG. https://codereview.chromium.org/2039673002/diff/220001/third_party/WebKit/Sou... third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp:277: DEFINE_THREAD_SAFE_STATIC_LOCAL(EnumerationHistogram, toBlobIdleSwitchedToMain, new EnumerationHistogram("Blink.Canvas.ToBlob.IdleTask.SwitchedToMain", IdleTaskNotSupported)); On 2016/06/13 20:15:06, xlai (Olivia) wrote: > The enum type "SwitchedToMain" is misleading. We are always on main thread. > Change the name to "IdleTaskSwitchedToMainThreadTask". Also change the other > names to look exactly same as the enum types in m_idleTaskStatus. Also, in the case where we switch to main, there are two interesting timing stats to record: the time spent encoding before and after the switch.
https://codereview.chromium.org/2039673002/diff/220001/third_party/WebKit/Sou... File third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp (right): https://codereview.chromium.org/2039673002/diff/220001/third_party/WebKit/Sou... third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp:207: toBlobPNGIdleEncodeCounter.count(elapsedTime * 1000000.0); On 2016/06/13 21:21:35, Justin Novosad wrote: > On 2016/06/13 20:15:06, xlai (Olivia) wrote: > > Move this whole block of code before this if-else block. > > actually, I was think more like doing "m_elapsedTime += ..." in the "if" part, > and recording the histogram in the "else" part. Same thing for JPEG. Yes, that makes perfect sense. https://codereview.chromium.org/2039673002/diff/220001/third_party/WebKit/Sou... third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp:227: toBlobJPEGIdleEncodeCounter.count(elapsedTime * 1000000.0); On 2016/06/13 20:15:06, xlai (Olivia) wrote: > Move this whole block of code before this if-else block. Using Justin's suggestion. https://codereview.chromium.org/2039673002/diff/220001/third_party/WebKit/Sou... third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp:277: DEFINE_THREAD_SAFE_STATIC_LOCAL(EnumerationHistogram, toBlobIdleSwitchedToMain, new EnumerationHistogram("Blink.Canvas.ToBlob.IdleTask.SwitchedToMain", IdleTaskNotSupported)); On 2016/06/13 20:15:06, xlai (Olivia) wrote: > The enum type "SwitchedToMain" is misleading. We are always on main thread. > Change the name to "IdleTaskSwitchedToMainThreadTask". Also change the other > names to look exactly same as the enum types in m_idleTaskStatus. Done. https://codereview.chromium.org/2039673002/diff/220001/third_party/WebKit/Sou... third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp:277: DEFINE_THREAD_SAFE_STATIC_LOCAL(EnumerationHistogram, toBlobIdleSwitchedToMain, new EnumerationHistogram("Blink.Canvas.ToBlob.IdleTask.SwitchedToMain", IdleTaskNotSupported)); On 2016/06/13 21:21:35, Justin Novosad wrote: > On 2016/06/13 20:15:06, xlai (Olivia) wrote: > > The enum type "SwitchedToMain" is misleading. We are always on main thread. > > Change the name to "IdleTaskSwitchedToMainThreadTask". Also change the other > > names to look exactly same as the enum types in m_idleTaskStatus. > > Also, in the case where we switch to main, there are two interesting timing > stats to record: the time spent encoding before and after the switch. This actually brings up another question: currently we measure the time spent encoding on the idle period. That time could be encoding the entire image, it could also be encoding part of the image because the switch could happen. In other words, that timing may not be so meaningful? https://codereview.chromium.org/2039673002/diff/240001/third_party/WebKit/Sou... File third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp (right): https://codereview.chromium.org/2039673002/diff/240001/third_party/WebKit/Sou... third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp:282: DEFINE_STATIC_LOCAL(EnumerationHistogram, toBlobIdleTaskStatus, ("Blink.Canvas.ToBlob.IdleTaskStatus", IdleTaskNotSupported)); xlai@: you are correct. I change the enum histogram like this. But one problem is that we cannot measure the case when toBlob failed because that happens in createNullAndInvokeCallback().
https://codereview.chromium.org/2039673002/diff/240001/third_party/WebKit/Sou... File third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp (right): https://codereview.chromium.org/2039673002/diff/240001/third_party/WebKit/Sou... third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp:214: m_elapsedTime += (WTF::monotonicallyIncreasingTime() - m_initiateStartTime); At each Idle slice, you are adding the time since start? This is not correct. https://codereview.chromium.org/2039673002/diff/240001/third_party/WebKit/Sou... third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp:234: m_elapsedTime += (WTF::monotonicallyIncreasingTime() - m_initiateStartTime); Not correct.
https://codereview.chromium.org/2039673002/diff/240001/third_party/WebKit/Sou... File third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp (right): https://codereview.chromium.org/2039673002/diff/240001/third_party/WebKit/Sou... third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp:214: m_elapsedTime += (WTF::monotonicallyIncreasingTime() - m_initiateStartTime); On 2016/06/22 14:38:57, Justin Novosad wrote: > At each Idle slice, you are adding the time since start? This is not correct. The new patch should have that fixed.
On 2016/06/22 15:40:41, xidachen wrote: > https://codereview.chromium.org/2039673002/diff/240001/third_party/WebKit/Sou... > File third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp > (right): > > https://codereview.chromium.org/2039673002/diff/240001/third_party/WebKit/Sou... > third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp:214: > m_elapsedTime += (WTF::monotonicallyIncreasingTime() - m_initiateStartTime); > On 2016/06/22 14:38:57, Justin Novosad wrote: > > At each Idle slice, you are adding the time since start? This is not correct. > > The new patch should have that fixed. I think this works. lgtm Please wait for Olivia's stamp of approval.
https://codereview.chromium.org/2039673002/diff/260001/third_party/WebKit/Sou... File third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp (right): https://codereview.chromium.org/2039673002/diff/260001/third_party/WebKit/Sou... third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp:213: toBlobPNGIdleEncodeCounter.count(m_elapsedTime * 1000000.0); I think there is a logic flaw. Think of the scenario when in the last idleEncodeRowsPng() call, the encoding finishes the last few rows of encoding without hitting the deadline in that particular idle period, so the above addition to m_elapsedTime at Line 201 is not executed. Then in here, the recording will miss out the time spent in the last idleEncodeRowsPng() call. https://codereview.chromium.org/2039673002/diff/260001/third_party/WebKit/Sou... third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp:244: m_elapsedTime += (WTF::monotonicallyIncreasingTime() - startTime); There is also a logic flaw here similar to the PNG one but the solution may be different. The function JPEGImageEncoder::progressiveEncodeRowsJpegHelper() will stop when it uses up the deadlineSeconds passed into it. If it manages to complete all encoding, you'll never hit the Line 244 and so your m_elapsedTime does not record the time spent in encoding. My suggestion for this one would be to move Line 244 to the position between Line 230 and Line 231. In that way, you accumulate m_elapsedTime regardless of failed, complete, in-progress status. https://codereview.chromium.org/2039673002/diff/260001/third_party/WebKit/Sou... third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp:283: toBlobIdleTaskStatus.count(m_idleTaskStatus); You miss out the case when m_idleTaskStatus==IdleTaskFailed because createBlobAndInvokeCallback() is only executed when idle encoding succeeds. https://codereview.chromium.org/2039673002/diff/260001/third_party/WebKit/Sou... File third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.h (right): https://codereview.chromium.org/2039673002/diff/260001/third_party/WebKit/Sou... third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.h:82: double m_elapsedTime = 0; Nit: move initialization of this member to the initialization list of constructor to be consistent with other members.
https://codereview.chromium.org/2039673002/diff/260001/third_party/WebKit/Sou... File third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp (right): https://codereview.chromium.org/2039673002/diff/260001/third_party/WebKit/Sou... third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp:213: toBlobPNGIdleEncodeCounter.count(m_elapsedTime * 1000000.0); On 2016/06/23 17:07:37, xlai (Olivia) wrote: > I think there is a logic flaw. Think of the scenario when in the last > idleEncodeRowsPng() call, the encoding finishes the last few rows of encoding > without hitting the deadline in that particular idle period, so the above > addition to m_elapsedTime at Line 201 is not executed. Then in here, the > recording will miss out the time spent in the last idleEncodeRowsPng() call. Good catch, the new patch should have that fixed. https://codereview.chromium.org/2039673002/diff/260001/third_party/WebKit/Sou... third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp:244: m_elapsedTime += (WTF::monotonicallyIncreasingTime() - startTime); On 2016/06/23 17:07:37, xlai (Olivia) wrote: > There is also a logic flaw here similar to the PNG one but the solution may be > different. The function JPEGImageEncoder::progressiveEncodeRowsJpegHelper() will > stop when it uses up the deadlineSeconds passed into it. If it manages to > complete all encoding, you'll never hit the Line 244 and so your m_elapsedTime > does not record the time spent in encoding. My suggestion for this one would be > to move Line 244 to the position between Line 230 and Line 231. In that way, you > accumulate m_elapsedTime regardless of failed, complete, in-progress status. Done. https://codereview.chromium.org/2039673002/diff/260001/third_party/WebKit/Sou... third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp:283: toBlobIdleTaskStatus.count(m_idleTaskStatus); On 2016/06/23 17:07:37, xlai (Olivia) wrote: > You miss out the case when m_idleTaskStatus==IdleTaskFailed because > createBlobAndInvokeCallback() is only executed when idle encoding succeeds. Done. https://codereview.chromium.org/2039673002/diff/260001/third_party/WebKit/Sou... File third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.h (right): https://codereview.chromium.org/2039673002/diff/260001/third_party/WebKit/Sou... third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.h:82: double m_elapsedTime = 0; On 2016/06/23 17:07:37, xlai (Olivia) wrote: > Nit: move initialization of this member to the initialization list of > constructor to be consistent with other members. Done.
https://codereview.chromium.org/2039673002/diff/260001/third_party/WebKit/Sou... File third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp (right): https://codereview.chromium.org/2039673002/diff/260001/third_party/WebKit/Sou... third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp:196: double startTime = WTF::monotonicallyIncreasingTime(); put this back. https://codereview.chromium.org/2039673002/diff/260001/third_party/WebKit/Sou... third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp:201: m_elapsedTime += (WTF::monotonicallyIncreasingTime() - startTime); Put this back. https://codereview.chromium.org/2039673002/diff/280001/third_party/WebKit/Sou... File third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp (right): https://codereview.chromium.org/2039673002/diff/280001/third_party/WebKit/Sou... third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp:199: double startTime = WTF::monotonicallyIncreasingTime(); This solution does not look great. Recording the time at every row encoding adds up the duration unnecessarily. I would suggest another approach that solves this issue but won't cause this (pls follow instructions on other comments). First of all, remove this line. https://codereview.chromium.org/2039673002/diff/280001/third_party/WebKit/Sou... third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp:207: m_elapsedTime += (WTF::monotonicallyIncreasingTime() - startTime); Remove this. https://codereview.chromium.org/2039673002/diff/280001/third_party/WebKit/Sou... third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp:212: m_idleTaskStatus = IdleTaskCompleted; Here, add m_elpaseTime += (WTF::monotonicallyIncreasingTime() - startTime);
https://codereview.chromium.org/2039673002/diff/280001/third_party/WebKit/Sou... File third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp (right): https://codereview.chromium.org/2039673002/diff/280001/third_party/WebKit/Sou... third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp:199: double startTime = WTF::monotonicallyIncreasingTime(); On 2016/06/24 14:56:09, xlai (Olivia) wrote: > This solution does not look great. Recording the time at every row encoding adds > up the duration unnecessarily. I would suggest another approach that solves this > issue but won't cause this (pls follow instructions on other comments). > First of all, remove this line. Thanks. Fixed in the new patch.
On 2016/06/24 15:27:55, xidachen wrote: > https://codereview.chromium.org/2039673002/diff/280001/third_party/WebKit/Sou... > File third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp > (right): > > https://codereview.chromium.org/2039673002/diff/280001/third_party/WebKit/Sou... > third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp:199: > double startTime = WTF::monotonicallyIncreasingTime(); > On 2016/06/24 14:56:09, xlai (Olivia) wrote: > > This solution does not look great. Recording the time at every row encoding > adds > > up the duration unnecessarily. I would suggest another approach that solves > this > > issue but won't cause this (pls follow instructions on other comments). > > First of all, remove this line. > > Thanks. Fixed in the new patch. lgtm. You need approval for the histograms.xml as well.
xidachen@chromium.org changed reviewers: + rkaplow@chromium.org
+rkaplow: could you take a look at the histogram changes?
https://codereview.chromium.org/2039673002/diff/300001/third_party/WebKit/Sou... File third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp (right): https://codereview.chromium.org/2039673002/diff/300001/third_party/WebKit/Sou... third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp:283: DEFINE_STATIC_LOCAL(EnumerationHistogram, toBlobIdleTaskStatus, ("Blink.Canvas.ToBlob.IdleTaskStatus", IdleTaskNotSupported)); this should be a MAX value that isn't part of the enum proper (i.e. add a max value to your enum and use that here)
https://codereview.chromium.org/2039673002/diff/300001/third_party/WebKit/Sou... File third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp (right): https://codereview.chromium.org/2039673002/diff/300001/third_party/WebKit/Sou... third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp:283: DEFINE_STATIC_LOCAL(EnumerationHistogram, toBlobIdleTaskStatus, ("Blink.Canvas.ToBlob.IdleTaskStatus", IdleTaskNotSupported)); On 2016/06/28 15:14:04, rkaplow wrote: > this should be a MAX value that isn't part of the enum proper (i.e. add a max > value to your enum and use that here) Done. Also updated in histograms.xml.
histogram owners: gentle ping.
https://codereview.chromium.org/2039673002/diff/320001/third_party/WebKit/Sou... File third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.h (right): https://codereview.chromium.org/2039673002/diff/320001/third_party/WebKit/Sou... third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.h:30: // enum used in histogram nit: Suggested phrasing: "This enum is used to back an UMA histogram, and should therefore be treated as append-only." https://codereview.chromium.org/2039673002/diff/320001/third_party/WebKit/Sou... third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.h:38: IdleTaskNotUsed, // Should not be seen in production nit: I'd name this "IdleTaskCount", which more clearly indicates that it should remain the last element in the enum. https://codereview.chromium.org/2039673002/diff/320001/tools/metrics/histogra... File tools/metrics/histograms/histograms.xml (right): https://codereview.chromium.org/2039673002/diff/320001/tools/metrics/histogra... tools/metrics/histograms/histograms.xml:3584: + <owner>xlai@chromium.org</owner> Out of curiousity, why are you not listing yourself as an owner of the histograms that you're adding? https://codereview.chromium.org/2039673002/diff/320001/tools/metrics/histogra... tools/metrics/histograms/histograms.xml:3585: + <summary>Time spent on idle encoding.</summary> What is "idle encoding"? In general, for events that measure a duration, it's best to be fairly precise about the start and end events, since they're not always obvious to someone just viewing the dashboard. https://codereview.chromium.org/2039673002/diff/320001/tools/metrics/histogra... tools/metrics/histograms/histograms.xml:3592: + Records the status of the idle tasks when finishing a toBlob call. nit: s/tasks/task ? https://codereview.chromium.org/2039673002/diff/320001/tools/metrics/histogra... tools/metrics/histograms/histograms.xml:3601: + Time elapsed from schedule initiate encoding to start initiate encoding. nit: s/schedule/scheduling and s/start/starting. Also, what does "initiate encoding" mean, exactly? Would it be semantically valid to simply drop both uses of "initiate" in this sentence? https://codereview.chromium.org/2039673002/diff/320001/tools/metrics/histogra... tools/metrics/histograms/histograms.xml:78494: + <int value="0" label="IdleTaskNotStarted"/> nit: These enum labels are fine if you want them to match the C++ code, but I'd personally recommend more readable names like "Not started", etc. https://codereview.chromium.org/2039673002/diff/320001/tools/metrics/histogra... tools/metrics/histograms/histograms.xml:78500: + <int value="6" label="IdleTaskNotUsed"/> nit: No need to list the unused overflow bucket in histograms.xml https://codereview.chromium.org/2039673002/diff/320001/tools/metrics/histogra... tools/metrics/histograms/histograms.xml:93624: +</histogram_suffixes> Could the above two histogram_suffixes elements be merged? They share the same suffixes, and seem likely to continue to do so if more suffixes are ever added.
isherman@: all comments are addressed. https://codereview.chromium.org/2039673002/diff/320001/third_party/WebKit/Sou... File third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.h (right): https://codereview.chromium.org/2039673002/diff/320001/third_party/WebKit/Sou... third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.h:30: // enum used in histogram On 2016/06/29 22:01:02, Ilya Sherman wrote: > nit: Suggested phrasing: "This enum is used to back an UMA histogram, and should > therefore be treated as append-only." Done. https://codereview.chromium.org/2039673002/diff/320001/third_party/WebKit/Sou... third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.h:38: IdleTaskNotUsed, // Should not be seen in production On 2016/06/29 22:01:02, Ilya Sherman wrote: > nit: I'd name this "IdleTaskCount", which more clearly indicates that it should > remain the last element in the enum. Done. https://codereview.chromium.org/2039673002/diff/320001/tools/metrics/histogra... File tools/metrics/histograms/histograms.xml (right): https://codereview.chromium.org/2039673002/diff/320001/tools/metrics/histogra... tools/metrics/histograms/histograms.xml:3584: + <owner>xlai@chromium.org</owner> On 2016/06/29 22:01:02, Ilya Sherman wrote: > Out of curiousity, why are you not listing yourself as an owner of the > histograms that you're adding? xlai@ implements the toBlob function and junov@ is our TL. I believe that xlai@ will be closely monitoring this histogram in the future. https://codereview.chromium.org/2039673002/diff/320001/tools/metrics/histogra... tools/metrics/histograms/histograms.xml:3585: + <summary>Time spent on idle encoding.</summary> On 2016/06/29 22:01:03, Ilya Sherman wrote: > What is "idle encoding"? In general, for events that measure a duration, it's > best to be fairly precise about the start and end events, since they're not > always obvious to someone just viewing the dashboard. Done. https://codereview.chromium.org/2039673002/diff/320001/tools/metrics/histogra... tools/metrics/histograms/histograms.xml:3592: + Records the status of the idle tasks when finishing a toBlob call. On 2016/06/29 22:01:03, Ilya Sherman wrote: > nit: s/tasks/task ? Done. https://codereview.chromium.org/2039673002/diff/320001/tools/metrics/histogra... tools/metrics/histograms/histograms.xml:3601: + Time elapsed from schedule initiate encoding to start initiate encoding. On 2016/06/29 22:01:03, Ilya Sherman wrote: > nit: s/schedule/scheduling and s/start/starting. Also, what does "initiate > encoding" mean, exactly? Would it be semantically valid to simply drop both > uses of "initiate" in this sentence? Done. https://codereview.chromium.org/2039673002/diff/320001/tools/metrics/histogra... tools/metrics/histograms/histograms.xml:78500: + <int value="6" label="IdleTaskNotUsed"/> On 2016/06/29 22:01:02, Ilya Sherman wrote: > nit: No need to list the unused overflow bucket in histograms.xml Done. https://codereview.chromium.org/2039673002/diff/320001/tools/metrics/histogra... tools/metrics/histograms/histograms.xml:93624: +</histogram_suffixes> On 2016/06/29 22:01:03, Ilya Sherman wrote: > Could the above two histogram_suffixes elements be merged? They share the same > suffixes, and seem likely to continue to do so if more suffixes are ever added. Done.
Metrics LGTM % a clarification request, which I think would be great to ask a teammate to help out with. Thanks =) https://codereview.chromium.org/2039673002/diff/340001/tools/metrics/histogra... File tools/metrics/histograms/histograms.xml (right): https://codereview.chromium.org/2039673002/diff/340001/tools/metrics/histogra... tools/metrics/histograms/histograms.xml:3586: + Time spent on encoding on the idle period of the main thread. Sorry, this is still unclear to me. Encoding and idle just don't make sense to me in combination, since encoding seems like it would, by definition, not be idle. I'd suggest asking a teammate to help you clarify this description -- I'd happily offer suggestions, but I'm really not sure what the intention is.
I put a much lengthy description here on the two metrics that cause confusion. Not sure whether there is a word limit on metric summary though. https://codereview.chromium.org/2039673002/diff/340001/tools/metrics/histogra... File tools/metrics/histograms/histograms.xml (right): https://codereview.chromium.org/2039673002/diff/340001/tools/metrics/histogra... tools/metrics/histograms/histograms.xml:3586: + Time spent on encoding on the idle period of the main thread. On 2016/06/30 07:35:51, Ilya Sherman wrote: > Sorry, this is still unclear to me. Encoding and idle just don't make sense to > me in combination, since encoding seems like it would, by definition, not be > idle. I'd suggest asking a teammate to help you clarify this description -- I'd > happily offer suggestions, but I'm really not sure what the intention is. This metric measures the total time spent on encoding all the rows of an image (jpeg or png), as part of canvas.toBlob API call, which occur during one or more idle periods on the main thread. This metric is useful in helping us adjust the IdleTaskCompleteTimeoutDelay in canvas.toBlob; when the encoding idle task is delayed for longer than IdleTaskCompleteTimeoutDelay, browser will switch to non-idle task to force encoding to happen on main thread. https://codereview.chromium.org/2039673002/diff/340001/tools/metrics/histogra... tools/metrics/histograms/histograms.xml:3602: + <summary>Time elapsed from scheduling encoding to starting encoding.</summary> This metric measures the time spent from initiating image encoding (jpeg or png) on idle task to the actual execution time of initiation, as part of canvas.toBlob API call. This metric is useful in helping us adjust the IdleTaskStartTimeoutDelay in canvas.toBlob; when the initialization idle task is delayed for longer than IdleTaskStartTimeoutDelay, browser will switch to non-idle task to force initialization and encoding to occur on main thread.
https://codereview.chromium.org/2039673002/diff/360001/tools/metrics/histogra... File tools/metrics/histograms/histograms.xml (right): https://codereview.chromium.org/2039673002/diff/360001/tools/metrics/histogra... tools/metrics/histograms/histograms.xml:3591: + IdleTaskCompleteTimeoutDelay in canvas.toBlob. histogram owners: could you please proof read the description here? Both me and xlai@ are not sure whether this is too long or not. https://codereview.chromium.org/2039673002/diff/360001/tools/metrics/histogra... tools/metrics/histograms/histograms.xml:3612: + IdleTaskStartTimeoutDelay in canvas.toBlob. histogram owners: please proof read the description here too. Thank you.
Thanks! The suggested descriptions are much clearer, and LGTM % a few grammatical nits (inline). There's no length limit on histograms descriptions. https://codereview.chromium.org/2039673002/diff/340001/tools/metrics/histogra... File tools/metrics/histograms/histograms.xml (right): https://codereview.chromium.org/2039673002/diff/340001/tools/metrics/histogra... tools/metrics/histograms/histograms.xml:3586: + Time spent on encoding on the idle period of the main thread. On 2016/06/30 14:42:31, xlai (Olivia) wrote: > On 2016/06/30 07:35:51, Ilya Sherman wrote: > > Sorry, this is still unclear to me. Encoding and idle just don't make sense > to > > me in combination, since encoding seems like it would, by definition, not be > > idle. I'd suggest asking a teammate to help you clarify this description -- > I'd > > happily offer suggestions, but I'm really not sure what the intention is. > > This metric measures the total time spent on encoding all the rows of an image > (jpeg or png), as part of canvas.toBlob API call, which occur during one or more > idle periods on the main thread. > > This metric is useful in helping us adjust the IdleTaskCompleteTimeoutDelay in > canvas.toBlob; when the encoding idle task is delayed for longer than > IdleTaskCompleteTimeoutDelay, browser will switch to non-idle task to force > encoding to happen on main thread. nit: s/as part of/as part of a nit: s/call, which occur/call. Encoding occurs nit: s/toBlob; when/toBlob. When nit: s/browser will/the browser will nit: s/switch to non-idle task/switch to a non-idle task nit: s/on main thread/on the main thread https://codereview.chromium.org/2039673002/diff/340001/tools/metrics/histogra... tools/metrics/histograms/histograms.xml:3602: + <summary>Time elapsed from scheduling encoding to starting encoding.</summary> On 2016/06/30 14:42:31, xlai (Olivia) wrote: > This metric measures the time spent from initiating image encoding > (jpeg or png) on idle task to the actual execution time of initiation, as part > of canvas.toBlob API call. > > This metric is useful in helping us adjust the IdleTaskStartTimeoutDelay in > canvas.toBlob; when the initialization idle task is delayed for longer than > IdleTaskStartTimeoutDelay, browser will switch to non-idle task to force > initialization and encoding to occur on main thread. (similar nits here)
The CQ bit was checked by xidachen@chromium.org to run a CQ dry run
Dry run: CQ is trying da patch. Follow status at https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...
The CQ bit was unchecked by commit-bot@chromium.org
Dry run: Try jobs failed on following builders: mac_chromium_compile_dbg_ng on master.tryserver.chromium.mac (JOB_FAILED, http://build.chromium.org/p/tryserver.chromium.mac/builders/mac_chromium_comp...)
The CQ bit was checked by xidachen@chromium.org to run a CQ dry run
Dry run: CQ is trying da patch. Follow status at https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...
The CQ bit was unchecked by commit-bot@chromium.org
Dry run: Try jobs failed on following builders: win_chromium_rel_ng on master.tryserver.chromium.win (JOB_FAILED, http://build.chromium.org/p/tryserver.chromium.win/builders/win_chromium_rel_...)
The CQ bit was checked by xidachen@chromium.org
The patchset sent to the CQ was uploaded after l-g-t-m from junov@chromium.org, xlai@chromium.org, isherman@chromium.org Link to the patchset: https://codereview.chromium.org/2039673002/#ps400001 (title: "fix compile error")
CQ is trying da patch. Follow status at https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...
Message was sent while issue was closed.
Committed patchset #21 (id:400001)
Message was sent while issue was closed.
CQ bit was unchecked.
Message was sent while issue was closed.
Description was changed from ========== Track performance of toBlob and its complete timeout delay This CL does two things: 1. Track the performance of a toBlob API call. Because toBlob has a call back, so we put a timer in the CanvasAsyncToBlob class. 2. Track how often the complete timeout delay happens in toBlob calls. BUG=612585, 608815 ========== to ========== Track performance of toBlob and its complete timeout delay This CL does two things: 1. Track the performance of a toBlob API call. Because toBlob has a call back, so we put a timer in the CanvasAsyncToBlob class. 2. Track how often the complete timeout delay happens in toBlob calls. BUG=612585, 608815 Committed: https://crrev.com/8c59e014125ad442b32c21b1724add603b489cc2 Cr-Commit-Position: refs/heads/master@{#403362} ==========
Message was sent while issue was closed.
Patchset 21 (id:??) landed as https://crrev.com/8c59e014125ad442b32c21b1724add603b489cc2 Cr-Commit-Position: refs/heads/master@{#403362} |