Add request timings and count histograms to telemetry. Closes #3552 #3622

jberryman · 2020-01-03T05:49:45Z

We upload a set of accumulating timers and counters to track service
time for different types of operations, across several dimensions (e.g.
did we hit the plan cache, was a remote involved, etc.)

Description

Affected components

Server
Tests

Related Issues

#3552 although metrics should hopefully give us general visibility into performance

Solution and Design

Steps to test and verify

run tests

Limitations, known bugs & workarounds

marked an unsafe forked thread as TODO immortal, but we should fix all of these together (see Audit uses of forkIO #3768 )
I didn't document changes in telemetry.rst; that doc is already stale. It would be nice if we could generate it from tests

Server checklist

Catalog upgrade

Does this PR change Hasura Catalog version?

No
Yes
- Updated docs with SQL for downgrading the catalog

Metadata

Does this PR add a new Metadata feature?

No
Yes
- Does run_sql auto manages the new metadata through schema diffing?
  - Yes
  - Not required
- Does run_sql auto manages the definitions of metadata on renaming?
  - Yes
  - Not required
- Does export_metadata/replace_metadata supports the new metadata added?
  - Yes
  - Not required

GraphQL

No new GraphQL schema is generated
New GraphQL schema is being generated:
- New types and typenames are correlated

Breaking changes

netlify · 2020-01-03T05:51:03Z

Deploy preview for hasura-docs ready!

Built with commit ee474ac

https://deploy-preview-3622--hasura-docs.netlify.com

hasura-bot · 2020-01-03T06:15:09Z

Review app for commit 5fd892f deployed to Heroku: https://hge-ci-pull-3622.herokuapp.com
Docker image for server: hasura/graphql-engine:pull3622-5fd892f7-dirty

jberryman · 2020-01-06T19:17:17Z

@0x777
I decided to base the resolution to #3547 on the work mentioned in the body of this PR to use some of the timing utilities. Can you please review 29b2963 ?

hasura-bot · 2020-01-06T19:30:13Z

Review app for commit c8d913f deployed to Heroku: https://hge-ci-pull-3622.herokuapp.com
Docker image for server: hasura/graphql-engine:pull3622-c8d913f8-dirty

server/src-lib/Hasura/Server/Logging.hs

hasura-bot · 2020-01-17T01:00:48Z

Review app for commit fdb4918 deployed to Heroku: https://hge-ci-pull-3622.herokuapp.com
Docker image for server: hasura/graphql-engine:pull3622-fdb49182-dirty

hasura-bot · 2020-01-17T04:00:08Z

Review app for commit ee474ac deployed to Heroku: https://hge-ci-pull-3622.herokuapp.com
Docker image for server: hasura/graphql-engine:pull3622-ee474ac0-dirty

netlify · 2020-01-21T14:26:21Z

Deploy preview for hasura-docs ready!

Built with commit 484ad79

https://deploy-preview-3622--hasura-docs.netlify.com

jberryman · 2020-01-21T15:23:29Z

@lexi-lambda @0x777 this is ready for review again

lexi-lambda

I’ve left a few small comments, but I’m going to defer to @0x777 to review the bulk of this change, since I think he has more context on it than I do, anyway (and I have plenty of other things to look at).

server/src-lib/Control/Concurrent/Extended.hs

server/src-lib/Data/Time/Clock/Units.hs

server/src-lib/Hasura/GraphQL/Transport/HTTP.hs

hasura-bot · 2020-01-22T06:40:07Z

Review app for commit 484ad79 deployed to Heroku: https://hge-ci-pull-3622.herokuapp.com
Docker image for server: hasura/graphql-engine:pull3622-484ad79c

server/src-lib/Hasura/Server/Logging.hs

jberryman · 2020-01-23T18:34:17Z

@lexi-lambda I think this should be ready now.

hasura-bot · 2020-01-30T18:38:15Z

Review app for commit ef79555 deployed to Heroku: https://hge-ci-pull-3622.herokuapp.com
Docker image for server: hasura/graphql-engine:pull3622-ef795559

lorenzo · 2020-01-30T18:43:23Z

server/src-lib/Hasura/Server/Telemetry/Counters.hs

+
+-- | 'RequestTimings' along with the count
+data RequestTimingsCount  =
+  RequestTimingsCount {


The current model does not seem to enable the ability to calculate percentiles, which are extremely useful for performance tracking. Would you guys be open to explore an alternative design that would enable calculations beyond totals and averages?

For now for the purposes of telemetry we're just collecting counts and timings for a few hand chosen buckets, which should be fine for our purposes, rather than using hdrhistogram or something similar. But I agree with you that percentiles are useful!

jberryman · 2020-01-30T19:09:41Z

@0x777 or @lexi-lambda

This should address Alexis's latest requested changes (use DiffTime instead of NominalDiffTime). History got somewhat worse as I didn't want to spend the time to again split up all the changes and squash them individually. I also added a few comments, added a fromUnits for conversions between units (including difftime and nominaldifftime), as I discovered realToFrac was a footgun.

0x777

LGTM

hasura-bot · 2020-02-03T16:35:14Z

Review app for commit 2d95118 deployed to Heroku: https://hge-ci-pull-3622.herokuapp.com
Docker image for server: hasura/graphql-engine:pull3622-2d951189

…3552 We upload a set of accumulating timers and counters to track service time for different types of operations, across several dimensions (e.g. did we hit the plan cache, was a remote involved, etc.) Also... Standardize on DiffTime as a standard duration type, and try to use it consistently. See discussion here: hasura#3584 (review) It should be possible to overwrite that module so the new threadDelay sticks per the pattern in hasura#3705 blocked on hasura#3558 Rename the Control.Concurrent.Extended.threadDelay to `sleep` since a naive use with a literal argument would be very bad! We catch a bug in 'computeTimeDiff'. Add convenient 'Read' instances to the time unit utility types. Make 'Second' a newtype to support this.

Add a new 'request_read_time' to the logging record. We also use 'withElapsedTime' to get proper monotonic clock for 'query_execution_time' as well.

…tegration tests

hasura-bot · 2020-02-04T00:51:23Z

Review app https://hge-ci-pull-3622.herokuapp.com is deleted

jberryman requested a review from lexi-lambda as a code owner January 3, 2020 05:49

jberryman force-pushed the 3552-gather-usage-telemetry-for-cache branch from 5fd892f to c8d913f Compare January 6, 2020 19:13

jberryman requested a review from 0x777 January 6, 2020 19:15

jberryman mentioned this pull request Jan 7, 2020

Better logging/telemetry for subscriptions #3656

Closed

jberryman mentioned this pull request Jan 14, 2020

Support graduating *.Extended modules to override standard modules with mixins #3705

Open

0x777 reviewed Jan 16, 2020

View reviewed changes

server/src-lib/Hasura/Server/Logging.hs Outdated Show resolved Hide resolved

jberryman force-pushed the 3552-gather-usage-telemetry-for-cache branch from c8d913f to fdb4918 Compare January 17, 2020 00:37

jberryman force-pushed the 3552-gather-usage-telemetry-for-cache branch from fdb4918 to ee474ac Compare January 17, 2020 03:45

jberryman force-pushed the 3552-gather-usage-telemetry-for-cache branch from ee474ac to 484ad79 Compare January 21, 2020 14:24

lexi-lambda reviewed Jan 21, 2020

View reviewed changes

0x777 reviewed Jan 22, 2020

View reviewed changes

server/src-lib/Hasura/Server/Logging.hs Show resolved Hide resolved

0x777 previously approved these changes Jan 23, 2020

View reviewed changes

jberryman dismissed 0x777’s stale review via 94719b2 January 23, 2020 17:29

jberryman force-pushed the 3552-gather-usage-telemetry-for-cache branch from 484ad79 to 94719b2 Compare January 23, 2020 17:29

jberryman requested a review from lexi-lambda January 27, 2020 15:37

lexi-lambda mentioned this pull request Jan 28, 2020

Scheduled triggers (close #1914) #3553

Merged

33 tasks

jberryman force-pushed the 3552-gather-usage-telemetry-for-cache branch from 94719b2 to ef79555 Compare January 30, 2020 18:26

lorenzo reviewed Jan 30, 2020

View reviewed changes

0x777 previously approved these changes Jan 31, 2020

View reviewed changes

jberryman added 3 commits February 3, 2020 18:50

Log time spent consuming request bytes from socket. Closes hasura#3547

f506cb3

Add a new 'request_read_time' to the logging record. We also use 'withElapsedTime' to get proper monotonic clock for 'query_execution_time' as well.

dev.sh: exit and report if graphql-engine fails to start up during in…

b863dc2

…tegration tests

lexi-lambda dismissed 0x777’s stale review via b863dc2 February 4, 2020 00:50

lexi-lambda force-pushed the 3552-gather-usage-telemetry-for-cache branch from 2d95118 to b863dc2 Compare February 4, 2020 00:50

lexi-lambda merged commit c90c75f into hasura:master Feb 4, 2020

jberryman deleted the 3552-gather-usage-telemetry-for-cache branch February 4, 2020 14:48

Add request timings and count histograms to telemetry. Closes #3552 #3622

Add request timings and count histograms to telemetry. Closes #3552 #3622

Uh oh!

Conversation

jberryman commented Jan 3, 2020 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Description

Affected components

Related Issues

Solution and Design

Steps to test and verify

Limitations, known bugs & workarounds

Server checklist

Catalog upgrade

Metadata

GraphQL

Breaking changes

Uh oh!

netlify bot commented Jan 3, 2020 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

hasura-bot commented Jan 3, 2020

Uh oh!

jberryman commented Jan 6, 2020

Uh oh!

hasura-bot commented Jan 6, 2020

Uh oh!

Uh oh!

hasura-bot commented Jan 17, 2020

Uh oh!

hasura-bot commented Jan 17, 2020

Uh oh!

netlify bot commented Jan 21, 2020

Uh oh!

jberryman commented Jan 21, 2020

Uh oh!

lexi-lambda left a comment

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

hasura-bot commented Jan 22, 2020

Uh oh!

Uh oh!

jberryman commented Jan 23, 2020

Uh oh!

hasura-bot commented Jan 30, 2020

Uh oh!

lorenzo Jan 30, 2020

Choose a reason for hiding this comment

Uh oh!

jberryman Jan 30, 2020

Choose a reason for hiding this comment

Uh oh!

jberryman commented Jan 30, 2020 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

0x777 left a comment

Choose a reason for hiding this comment

Uh oh!

hasura-bot commented Feb 3, 2020

Uh oh!

hasura-bot commented Feb 4, 2020

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

5 participants

jberryman commented Jan 3, 2020 •

edited

Loading

netlify bot commented Jan 3, 2020 •

edited

Loading

jberryman commented Jan 30, 2020 •

edited

Loading