这是indexloc提供的服务,不要输入任何密码
Skip to content

Conversation

@hgiasac
Copy link
Contributor

@hgiasac hgiasac commented Dec 24, 2019

Description

Affected components

  • Server
  • Console
  • CLI
  • Docs
  • Community Content
  • Build System
  • Tests
  • Other (list it)

Related Issues

Solution and Design

Add more two fields query_execution_time and response_size into ws-server event detail.
They are computed on message_sent data event only.

{
  "type":"ws-server",
  "timestamp":"2019-12-17T11:46:29.190+0700",
  "level":"debug",
  "detail": {
    "metadata": {
        "response_size":21,
        "query_execution_time": 8.54369e-4
    },
    "event": {
      "type":"message_sent",
      "detail": "{
        "type":"data",
        "id":"1",
        "payload": {
            ...
          }
        }
      }"
    },
    "websocket_id":"4c9dffd6-aa14-4539-b935-f40dd5647b2b"
  }  
}

Live query TQueue content are changed from BL.ByteString to WSQueueResponse ADT:

data WSQueueResponse
  = WSQueueResponse
  { _wsqrMessage   :: !BL.ByteString
  , _wsqrEventInfo :: !(Maybe WSEventInfo)
  }

Add LiveQueryMetadata ADT as additional parameter in live query OnChange callback:

data LiveQueryMetadata
  = LiveQueryMetadata
  { _lqmExecutionTime :: !(Maybe Double)
  }

type OnChange = GQResponse -> LiveQueryMetadata -> IO ()

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

  • No Breaking changes

  • There are breaking changes:

    1. Metadata API

      Existing query types:

      • Modify args payload which is not backward compatible
      • Behavioural change of the API
      • Change in response JSON schema
      • Change in error code
    2. GraphQL API

      Schema Generation:

      • Change in any NamedType
      • Change in table field names

      Schema Resolve:-

      • Change in treatment of null value for any input fields
    3. Logging

      • Log JSON schema has changed
      • Log type names have changed

Add more two fields query_execution_time and response_size into ws-server event detail. However, normal user won't see any difference because those logs are only sent on debug level

Steps to test and verify

Run graphql engine with --log-level=debug
Request a subcription query
View stdout logs

Limitations, known bugs & workarounds

@hgiasac hgiasac added the c/server Related to server label Dec 24, 2019
@netlify
Copy link

netlify bot commented Dec 24, 2019

Deploy preview for hasura-docs ready!

Built with commit 702e809

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

@hasura-bot
Copy link
Contributor

Review app for commit c77f54d deployed to Heroku: https://hge-ci-pull-3584.herokuapp.com
Docker image for server: hasura/graphql-engine:pull3584-c77f54db

@hgiasac
Copy link
Contributor Author

hgiasac commented Dec 26, 2019

New log json structure is.

{
  "type":"ws-server",
  "timestamp":"2019-12-17T11:46:29.190+0700",
  "level":"debug",
  "detail": {
    "metadata": {
        "response_size":21,
        "query_execution_time": 8.54369e-4
    },
    "event": {
       ...
    },
    "websocket_id":"4c9dffd6-aa14-4539-b935-f40dd5647b2b"
  }  
}

response_size and query_execution_time are outside. It won't affect ws message structure

Copy link
Contributor

@ecthiender ecthiender left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Overall looks good. Added some minor comments regarding readability of code. Let me know if that makes sense.

@ecthiender
Copy link
Contributor

Would be great if @lexi-lambda can also take a brief look at it (to check if it makes sense to calculate the exec time and put it in the queue).

@ecthiender ecthiender changed the title add query_execution_time and response_size to ws-server logs add query execution time and response size to ws-server logs in websocket transport Dec 27, 2019
@ecthiender ecthiender added the s/wip Status: This issue is a work in progress label Dec 27, 2019
@hasura-bot
Copy link
Contributor

Review app for commit 3041d1d deployed to Heroku: https://hge-ci-pull-3584.herokuapp.com
Docker image for server: hasura/graphql-engine:pull3584-3041d1d6

@hasura-bot
Copy link
Contributor

Review app for commit 4e32bbc deployed to Heroku: https://hge-ci-pull-3584.herokuapp.com
Docker image for server: hasura/graphql-engine:pull3584-4e32bbc9

ecthiender
ecthiender previously approved these changes Dec 27, 2019
Copy link
Contributor

@ecthiender ecthiender left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM

Copy link
Contributor

@lexi-lambda lexi-lambda left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Left a few minor comments.

@hasura-bot
Copy link
Contributor

Review app for commit b94eb84 deployed to Heroku: https://hge-ci-pull-3584.herokuapp.com
Docker image for server: hasura/graphql-engine:pull3584-b94eb842

Comment on lines +106 to +107
-- ^ extra metadata that we use for other actions, such as print log
-- we don't want to inlcude them into websocket message payload
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Please use Haddock comment syntax for comments like there where it makes sense. (I’ve made the change here myself, since it’s a small thing, but just so you know in the future.)

@hasura-bot
Copy link
Contributor

Review app for commit 702e809 deployed to Heroku: https://hge-ci-pull-3584.herokuapp.com
Docker image for server: hasura/graphql-engine:pull3584-702e809b

@lexi-lambda lexi-lambda merged commit 2aba7ed into hasura:master Jan 7, 2020
@hasura-bot
Copy link
Contributor

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

_ -> "for the following reasons:\n" <> T.unlines
(map (("" <>) . showError) errors)

withElapsedTime :: MonadIO m => m a -> m (NominalDiffTime, a)
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

FWIW I wrote a similar utility function in https://github.com/hasura/graphql-engine/pull/3622/files#diff-b4adc70671eae2d8ba4ad21bd16ede86R104 I considered NominalDiffTime but ultimately went a different route since having a duration type tagged with a unit is less error-prone when using literals and when serializing. But there are tradeoffs for both approaches...

I also use the monotonic clock, which is a more strictly correct way to get timing, but again this probably doesn't matter (unless some other part of the code blows up or loops on unexpected negative duration etc...)

Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@lexi-lambda @hgiasac actually I think I need an opinion here. I'm rebasing my PR again on this and now there's a block of code we time twice ) in two different ways which doesn't make much sense.

I'm okay refactoring to use NominalDiffTime (or maybe even better, a newtype called Seconds) as a standard duration type

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@jberryman I wrote a library for doing type-safe unit conversion stuff in Data.Time.Clock.Units. It’s all based on DiffTime, though, not NominalDiffTime, since as you mention it’s the Right Thing here.

That said, I’ve never actually been 100% clear on how you’re supposed to actually get a DiffTime with the usual Data.Time.Clock API. As far as I can tell, it doesn’t expose a monotonic clock. There’s Data.Time.Clock.TAI, but there’s no guaranteed way to access a clock that produces an AbsoluteTime.

My preference would be to wrap GHC.Clock so that it produces a DiffTime and use that, along with the Data.Time.Clock.Units module mentioned above. Does that seem reasonable to you?

Copy link
Collaborator

@jberryman jberryman Jan 9, 2020

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Oh cool, I looked but totally missed that module. It looks good!

Types help a lot but time is crazy; my understanding, which is probably not entirely correct:

  • AbsoluteTime was defined to be an epoch time, to support the possibility of a correct difference operation (DiffTime); no ecosystem really developed out of these (or maybe there are some good libraries out there! I've only used timezone-olsen which uses completely separate types IIRC)
  • NominalDiffTime (nominal in the sense of "it doesn't really work"?) was defined separately with much self-loathing to support the useful but formally nonsensical diffing of UTCTime (which as they note is only correct (or legally binding?) if the UTCTimes are earlier than a horizon of 6 months from when you perform the calculation...)
  • I think there fundamentally is not a way to get AbsoluteTime as they define it from your machine without a table of leap seconds; POSIXTime is what we usually think of when we think of an epoch time but is, I think, approximate wrt leap seconds (...very unclear about this)
  • the monotonic clock is orthogonal to all of this; it's just an API that gives you a ticking counter that only increases (the regular system clock can jump forward or backwards). afaiu a reading of the monotonic clock has no meaning; it's only good for measuring durations.

Sooooo ... (what were we talking about?)

My preference would be to wrap GHC.Clock so that it produces a DiffTime and use that, along with the Data.Time.Clock.Units module mentioned above. Does that seem reasonable to you?

I think either DiffTime or NominalDiffTime are equally valid to use as a duration type in that module, but NominalDiffTime is the one you can actually use in calculations with time moments (for better or worse). So we might want to consider using NominalDiffTime in your module, but I have no real opinion there and yes that sounds good!

Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@lexi-lambda also re. an algebra for time etc., I couldn't remember the name of this structure and had to email a colleague: https://ro-che.info/articles/2013-01-08-torsors

Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Oh I see you can get an AbsoluteTime with http://hackage.haskell.org/package/time-1.9.3/docs/Data-Time-Clock-System.html#v:systemToTAITime , but now I'm a more lost...

jberryman added a commit to jberryman/graphql-engine that referenced this pull request Jan 17, 2020
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.
jberryman added a commit to jberryman/graphql-engine that referenced this pull request Jan 21, 2020
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.
jberryman added a commit to jberryman/graphql-engine that referenced this pull request Jan 23, 2020
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.
jberryman added a commit to jberryman/graphql-engine that referenced this pull request Jan 30, 2020
…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.
lexi-lambda pushed a commit to jberryman/graphql-engine that referenced this pull request Feb 4, 2020
…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.
polRk pushed a commit to polRk/graphql-engine that referenced this pull request Feb 12, 2020
polRk pushed a commit to polRk/graphql-engine that referenced this pull request Feb 12, 2020
…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.
nizar-m pushed a commit to nizar-m/graphql-engine that referenced this pull request Apr 19, 2020
…cket transport (hasura#3584)

  - cherry-picked the above commit (2aba7ed) from master into
  ratelimit-changes-v1stable
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

c/server Related to server s/wip Status: This issue is a work in progress

Projects

None yet

Development

Successfully merging this pull request may close these issues.

6 participants