Closed Bug 1325322 Opened 3 years ago Closed 3 years ago

Change HTTP_NET_VS_CACHE_ probes to cover bigger time span

Categories

(Core :: Networking: Cache, defect)

defect
Not set

Tracking

()

RESOLVED FIXED
mozilla54
Tracking Status
firefox53 --- affected
firefox54 --- fixed

People

(Reporter: michal, Assigned: junior)

References

(Blocks 1 open bug)

Details

(Whiteboard: [necko-active])

Attachments

(1 file, 6 obsolete files)

The current range +-500ms is insufficient. Around 30% of samples are out of bounds and the worst case is HTTP_NET_VS_CACHE_ONSTART_QBIG_NORMALPRI with 70% of samples. We should also reconsider limits for small, medium and big cache IO queue length. Ideally we would find such limit for big queue length where network starts to win over the cache.
Assignee: nobody → juhsu
Whiteboard: [necko-active]
What came to my mind is to save a math log time.
That is, after we get a diff in ms, we save log_2(diff) + 20 with "high" = 40 and "n_bucket" = 40.

We can gather +/- 10 minutes data and do not waste much space for large time diff.
IMO we can do this after we reduce the probes in Bug 1325090
I'd like to add one more probe with every HTTP_NET_VS_CACHE_*

Taking HTTP_NET_VS_CACHE_ON_START_QSMALL_HIGHPRI as example,
I'd like to add one more probe HTTP_NET_VS_CACHE_ON_START_QSMALL_HIGHPRI_LOG2,
which record the time described in Comment 1.

FWIW, 16 probes are left in current implementation of Bug 1325090.

What do you think, Michal?
Flags: needinfo?(michal.novotny)
Attached patch time_span-WIP-v1 (obsolete) — Splinter Review
What do you think about this approach, michal?

TODO: add HTTP_NET_VS_CACHE_*_LOG2 for each probe
Flags: needinfo?(michal.novotny)
Attachment #8829371 - Flags: feedback?(michal.novotny)
(In reply to Junior[:junior] from comment #3)
> I'd like to add one more probe with every HTTP_NET_VS_CACHE_*
> 
> Taking HTTP_NET_VS_CACHE_ON_START_QSMALL_HIGHPRI as example,
> I'd like to add one more probe
> HTTP_NET_VS_CACHE_ON_START_QSMALL_HIGHPRI_LOG2,
> which record the time described in Comment 1.
> 
> FWIW, 16 probes are left in current implementation of Bug 1325090.
> 
> What do you think, Michal?

I don't think it's worth collecting both, linear and logarithmic values. Also the logarithmic resolution wouldn't be ideal for us, it's too fine for the first few buckets and then too coarse. Maybe we could grow the intervals of the buckets in steps. Something like 10ms from 0 to 100ms, 50ms from 100ms to 1000ms, etc...
Attachment #8829371 - Flags: feedback?(michal.novotny)
After considering the resolution and readability, I'd like to implement as following:

bucket 4 to 39 indicates net-win; 40 to 76 for cache-win.

Let's focus on cache-win case first,
40 to 49 divide 0 to 100 ms, step by 10ms.
50 is reserved
51 to 59 divide 100 to 1000 ms, step by 100ms.
60 is reserved.
61 to 69 divide 1s to 10s, step by 1 sec.
70 is reserved.
71 to 75 divide 10s to 1m, step by 10 seconds.

And reflection for the net-win case.
39 to 30 for -1 to -100ms
29 is reserved
28 to 20 for -100 to -1second
19 is reserved
18 to 10 for -1s to -10s,
9 is reserved
8 to 4 for -10s to -1m
0 to 3 are reserved
maybe 76 for cache-win by more than 1 minute,
3 for net-win by 1 minute
Attached patch time_span-WIP-v2 (obsolete) — Splinter Review
Implement by last two comments.
Only do for one probe in this patch.
Attachment #8829371 - Attachment is obsolete: true
Attachment #8830666 - Flags: feedback?(michal.novotny)
Comment on attachment 8830666 [details] [diff] [review]
time_span-WIP-v2

Review of attachment 8830666 [details] [diff] [review]:
-----------------------------------------------------------------

(In reply to Junior[:junior] from comment #6)
> After considering the resolution and readability, I'd like to implement as
> following:
> 
> bucket 4 to 39 indicates net-win; 40 to 76 for cache-win.
> 
> Let's focus on cache-win case first,
> 40 to 49 divide 0 to 100 ms, step by 10ms.
> 50 is reserved

I don't like these holes and also I don't think it makes the data more readable.

> And reflection for the net-win case.
> 39 to 30 for -1 to -100ms

This is not true. The function returns 39 for 0, 38 for -10, 28 for -100, ...

We should have it symmetrical. Let's have bucket 40 for 0, 41 for 1 to 10, 39 for -1 to -10, etc. To have it really symmetrical we need 81 buckets.
Attachment #8830666 - Flags: feedback?(michal.novotny) → feedback+
Attached patch time_span-v3 (obsolete) — Splinter Review
Tend to sync with other probes in the next patch.
Attachment #8830666 - Attachment is obsolete: true
Attachment #8834329 - Flags: review?(michal.novotny)
Comment on attachment 8834329 [details] [diff] [review]
time_span-v3

This looks good to me.
Attachment #8834329 - Flags: review?(michal.novotny) → feedback+
Attached patch time_span-v4 (obsolete) — Splinter Review
Attachment #8834329 - Attachment is obsolete: true
Attachment #8834737 - Flags: review?(michal.novotny)
Comment on attachment 8834737 [details] [diff] [review]
time_span-v4

Review of attachment 8834737 [details] [diff] [review]:
-----------------------------------------------------------------

Looks good. We need a data review for this...
Attachment #8834737 - Flags: review?(michal.novotny)
Attachment #8834737 - Flags: review?(benjamin)
Attachment #8834737 - Flags: review+
Comment on attachment 8834737 [details] [diff] [review]
time_span-v4

Review of attachment 8834737 [details] [diff] [review]:
-----------------------------------------------------------------

::: netwerk/protocol/http/nsHttpChannel.cpp
@@ +8322,5 @@
> +{
> +	int64_t absBucketIndex =
> +		std::lower_bound(positiveBucketLevels,
> +	                     positiveBucketLevels + kPositiveBucketNumbers,
> +	                     abs(difftime_ms))

I'm not sure which is better, std::abs or mozilla:Abs, but I'll add a namespace-specifier before landed.
Comment on attachment 8834737 [details] [diff] [review]
time_span-v4

A little hard to review because raw patches of JSON are dump, but this looks fine. Just don't rely on any automated alerts for these metrics: it won't work for nonscalar values.
Attachment #8834737 - Flags: review?(benjamin) → review+
Attached patch time_span-v5 (obsolete) — Splinter Review
Fix a nit, carry r+
tree result
 https://treeherder.mozilla.org/#/jobs?repo=try&revision=f273810983b7bf90da7409a9a6becb4266ae1da6
Attachment #8834737 - Attachment is obsolete: true
Attachment #8836628 - Flags: review+
Keywords: checkin-needed
Pushed by cbook@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/81388598aeac
add HTTP_NET_VS_CACHE_* for large time span, r=michal
Keywords: checkin-needed
Backed out for build bustage, at least on Windows:

https://hg.mozilla.org/integration/mozilla-inbound/rev/28ed47ff51b2dfec519b56d6d676dcbf27d47c39

Push with bustage: https://treeherder.mozilla.org/#/jobs?repo=mozilla-inbound&revision=a30525f7b3955104c0111bc190d46eb30e5416a7&
Failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=76803104&repo=mozilla-inbound

12:06:02     INFO -  z:/build/build/src/sccache2/sccache.exe z:/build/build/src/vs2015u3/VC/bin/amd64_x86/cl.exe -Fovp8_enc_stubs_sse2.obj -c  -DNDEBUG=1 -DTRIMMED=1 -DHAVE_CONFIG_H=vpx_config.h -DSTATIC_EXPORTABLE_JS_API -DMOZ_HAS_MOZGLUE -DMOZILLA_INTERNAL_API -DIMPL_LIBXUL -Iz:/build/build/src/media/libvpx -Iz:/build/build/src/obj-firefox/media/libvpx  -Iz:/build/build/src/obj-firefox/dist/include  -Iz:/build/build/src/obj-firefox/dist/include/nspr -Iz:/build/build/src/obj-firefox/dist/include/nss        -MD -FI z:/build/build/src/obj-firefox/mozilla-config.h -DMOZILLA_CLIENT -deps.deps/vp8_enc_stubs_sse2.obj.pp  -TC -nologo -wd4091 -D_HAS_EXCEPTIONS=0 -W3 -Gy -Zc:inline -utf-8 -arch:SSE2 -FS -Gw -wd4244 -wd4267 -we4553  -Z7 -O1 -Oi -Oy- -Iz:/build/build/src/media/libvpx/config/win/ia32/ -Iz:/build/build/src/media/libvpx/libvpx -Iz:/build/build/src/media/libvpx/config   z:/build/build/src/media/libvpx/libvpx/vp8/encoder/x86/vp8_enc_stubs_sse2.c
12:06:02     INFO -  Unified_cpp_protocol_http1.cpp
12:06:02     INFO -  z:\build\build\src\vs2015u3\VC\include\xstddef(324): error C2220: warning treated as error - no 'object' file generated
12:06:02     INFO -  z:\build\build\src\vs2015u3\VC\include\algorithm(2178): note: see reference to function template instantiation 'bool std::less<void>::operator ()<const int64_t&,const _Ty&>(_Ty1,_Ty2) const' being compiled
12:06:02     INFO -          with
12:06:02     INFO -          [
12:06:02     INFO -              _Ty=mozilla::detail::AbsReturnType<__int64>::Type,
12:06:02     INFO -              _Ty1=const int64_t &,
12:06:02     INFO -              _Ty2=const mozilla::detail::AbsReturnType<__int64>::Type &
12:06:02     INFO -          ]
12:06:02     INFO -  z:\build\build\src\vs2015u3\VC\include\algorithm(2198): note: see reference to function template instantiation '_FwdIt std::_Lower_bound_unchecked<_Iter,_Ty,_Pr>(_FwdIt,_FwdIt,const _Ty &,_Pr &)' being compiled
12:06:02     INFO -          with
12:06:02     INFO -          [
12:06:02     INFO -              _FwdIt=const int64_t *,
12:06:02     INFO -              _Iter=const int64_t *,
12:06:02     INFO -              _Ty=mozilla::detail::AbsReturnType<__int64>::Type,
12:06:02     INFO -              _Pr=std::less<void>
12:06:02     INFO -          ]
12:06:02     INFO -  z:\build\build\src\vs2015u3\VC\include\algorithm(2206): note: see reference to function template instantiation '_FwdIt *std::lower_bound<_FwdIt,_Ty,std::less<void>>(_FwdIt,_FwdIt,const _Ty &,_Pr)' being compiled
12:06:02     INFO -          with
12:06:02     INFO -          [
12:06:02     INFO -              _FwdIt=const int64_t *,
12:06:02     INFO -              _Ty=mozilla::detail::AbsReturnType<__int64>::Type,
12:06:02     INFO -              _Pr=std::less<void>
12:06:02     INFO -          ]
12:06:02     INFO -  z:/build/build/src/netwerk/protocol/http/nsHttpChannel.cpp(8344): note: see reference to function template instantiation '_FwdIt std::lower_bound<const int64_t*,mozilla::detail::AbsReturnType<__int64>::Type>(_FwdIt,_FwdIt,const _Ty &)' being compiled
12:06:02     INFO -          with
12:06:02     INFO -          [
12:06:02     INFO -              _FwdIt=const int64_t *,
12:06:02     INFO -              _Ty=mozilla::detail::AbsReturnType<__int64>::Type
12:06:02     INFO -          ]
12:06:02     INFO -  Warning: C4018 in z:\build\build\src\vs2015u3\VC\include\xstddef: '<': signed/unsigned mismatch
12:06:02     INFO -  z:\build\build\src\vs2015u3\VC\include\xstddef(324): warning C4018: '<': signed/unsigned mismatch
12:06:02     INFO -  z:/build/build/src/config/rules.mk:1016: recipe for target 'Unified_cpp_protocol_http1.obj' failed
12:06:02     INFO -  mozmake.EXE[5]: *** [Unified_cpp_protocol_http1.obj] Error 2
Flags: needinfo?(juhsu)
Attached patch time_span-v6 (obsolete) — Splinter Review
I believe I miss the header file.
Let's see the treeherder
 https://treeherder.mozilla.org/#/jobs?repo=try&revision=2873382c8148c54d139cd938a64d4a2cef9eaf52
Attachment #8836628 - Attachment is obsolete: true
Flags: needinfo?(juhsu)
Attachment #8836966 - Flags: review+
Attached patch time_span-v7Splinter Review
Fix bustage
Attachment #8836966 - Attachment is obsolete: true
Attachment #8837064 - Flags: review+
Keywords: checkin-needed
Pushed by mozilla@noorenberghe.ca:
https://hg.mozilla.org/integration/mozilla-inbound/rev/15aaabd6d6d6
add HTTP_NET_VS_CACHE_* for large time span, r=michal
Keywords: checkin-needed
https://hg.mozilla.org/mozilla-central/rev/15aaabd6d6d6
Status: NEW → RESOLVED
Closed: 3 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla54
You need to log in before you can comment on or make changes to this bug.