{"action":"created","issue":{"url":"https://api.github.com/repos/percona/qan-agent/issues/53","repository_url":"https://api.github.com/repos/percona/qan-agent","labels_url":"https://api.github.com/repos/percona/qan-agent/issues/53/labels{/name}","comments_url":"https://api.github.com/repos/percona/qan-agent/issues/53/comments","events_url":"https://api.github.com/repos/percona/qan-agent/issues/53/events","html_url":"https://github.com/percona/qan-agent/pull/53","id":241747036,"number":53,"title":"PMM-1081: PS collector doesn't work for queries that don't show every interval","user":{"login":"arvenil","id":450355,"avatar_url":"https://avatars0.githubusercontent.com/u/450355?v=4","gravatar_id":"","url":"https://api.github.com/users/arvenil","html_url":"https://github.com/arvenil","followers_url":"https://api.github.com/users/arvenil/followers","following_url":"https://api.github.com/users/arvenil/following{/other_user}","gists_url":"https://api.github.com/users/arvenil/gists{/gist_id}","starred_url":"https://api.github.com/users/arvenil/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/arvenil/subscriptions","organizations_url":"https://api.github.com/users/arvenil/orgs","repos_url":"https://api.github.com/users/arvenil/repos","events_url":"https://api.github.com/users/arvenil/events{/privacy}","received_events_url":"https://api.github.com/users/arvenil/received_events","type":"User","site_admin":false},"labels":[],"state":"open","locked":false,"assignee":null,"assignees":[],"milestone":null,"comments":0,"created_at":"2017-07-10T15:10:02Z","updated_at":"2017-07-18T15:16:45Z","closed_at":null,"pull_request":{"url":"https://api.github.com/repos/percona/qan-agent/pulls/53","html_url":"https://github.com/percona/qan-agent/pull/53","diff_url":"https://github.com/percona/qan-agent/pull/53.diff","patch_url":"https://github.com/percona/qan-agent/pull/53.patch"},"body":"# Issue\r\n\r\nPerformance Schema Monitor treats queries that don't show up every snapshot as `new queries`.\r\nIf query is run in intervals longer than 60s it will be incorrectly scrapped as `new query` and so its full `query count` will be taken as metric but instead the difference to previous value should be taken.\r\n\r\nIn other words query needs to be executed every interval (e.g. every 60s) to be properly recorded. \r\n\r\n# Proof\r\n\r\n```term\r\nFAIL: perfschema_test.go:659: WorkerTestSuite.Test005\r\n\r\nperfschema_test.go:719:\r\n    assert.Equal(t, expect, res)\r\n/home/travis/gopath/src/github.com/percona/qan-agent/vendor/github.com/stretchr/testify/assert/assertions.go:239:\r\n    t.Errorf(\"%s\", \"\\r\"+getWhitespaceString()+labeledOutput(content...))\r\n\tError Trace:\tperfschema_test.go:719\r\n\tError:      \tNot equal: \r\n\t            \texpected: &report.Result{Global:(*event.Class)(0xc420146f60), Class:[]*event.Class{(*event.Class)(0xc420146fc0), (*event.Class)(0xc420147020)}, RateLimit:0x0, RunTime:0, StopOffset:0, Error:\"\"}\r\n\t            \tactual: &report.Result{Global:(*event.Class)(0xc420146c60), Class:[]*event.Class{(*event.Class)(0xc420146cc0), (*event.Class)(0xc420146d20)}, RateLimit:0x0, RunTime:0, StopOffset:0, Error:\"\"}\r\n\r\n\t            \tDiff:\r\n\t            \t--- Expected\r\n\t            \t+++ Actual\r\n\t            \t@@ -188,3 +188,3 @@\r\n\t            \t   }),\r\n\t            \t-  TotalQueries: (uint) 3,\r\n\t            \t+  TotalQueries: (uint) 1003,\r\n\t            \t   UniqueQueries: (uint) 2,\r\n\t            \t@@ -577,3 +577,3 @@\r\n\t            \t    }),\r\n\t            \t-   TotalQueries: (uint) 2,\r\n\t            \t+   TotalQueries: (uint) 1002,\r\n\t            \t    UniqueQueries: (uint) 0,\r\n```\r\n[source](https://travis-ci.org/percona/qan-agent/jobs/252040366#L674-L697)\r\n\r\n\r\n# Explanation \r\n\r\nPerformance Schema collector works by taking snapshots of `performance_schema.events_statements_summary_by_digest` every `interval` seconds, and then by comparing current snapshot with previous snapshot it calculates the change in metric value.\r\n\r\nLet's say snapshots are taken every `60s` (default interval). Below are 3 snapshots and then metrics that are produced from them.  To make data more clear all metrics got removed except `CountStar` which is `query count`. Let's call query with digest `11111111111111111111111111111111` the Query `1` and query with digest `22222222222222222222222222222222` the Query `2`.\r\n\r\n* Snapshot 1 - Query `1` was executed `1` time so far, Query `2` was executed `1000` times so far. \r\n  ```\r\n  [\r\n\t{\r\n\t\t\"Digest\": \"11111111111111111111111111111111\",\r\n\t\t\"CountStar\": 1\r\n\t},\r\n\t{\r\n\t\t\"Digest\": \"22222222222222222222222222222222\",\r\n\t\t\"CountStar\": 1000\r\n\t}\r\n  ]\r\n  ```\r\n* Snapshot 2 - Query `2` was not executed during this time frame, so it doesn't show up in the snapshot. Query `1` was executed `1` time in this snapshot so in total `2` times.\r\n  ```\r\n  [\r\n\t{\r\n\t\t\"Digest\": \"11111111111111111111111111111111\",\r\n\t\t\"CountStar\": 2\r\n\t}\r\n  ]\r\n  ```\r\n\r\n* Snapshot 3 - Query `1` was executed `1` time in this snapshot so in total `3` times. Query `2` shows up again and it was executed `2` times in this snapshot so in total `1002` times.\r\n  ```\r\n  [\r\n\t{\r\n\t\t\"Digest\": \"11111111111111111111111111111111\",\r\n\t\t\"CountStar\": 3\r\n\t},\r\n\t{\r\n\t\t\"Digest\": \"22222222222222222222222222222222\",\r\n\t\t\"CountStar\": 1002\r\n\t}\r\n  ]\r\n  ```\r\n\r\nSo we have `CountStar` (`query count`):\r\n\r\n* First interval:\r\n  * Query `1`: `1`\r\n  * Query `2`: `1000`\r\n* Second interval:\r\n  * Query `1`: `2`\r\n* Third interval:\r\n  * Query `1`: `3`\r\n  * Query `2`: `1002`\r\n\r\nNow to calculate metrics we need to have 2 snapshots, so we skip first interval. We can create metrics only between:\r\n* 1st and 2nd snapshot\r\n  * Query `1` SUM: `2 - 1 = 1`\r\n  * Query `2` SUM: metric is not generate for this because we don't have it in second snapshot, so we have nothing to compare too.\r\n* 2nd and 3rd snapshot\r\n  * Query `1` SUM: `3 - 2 = 1`\r\n  * **Query `2` SUM: since Query `2` doesn't exist in previous snapshot then it's thought to be new query that was executed `1002` times during this interval. This is wrong as if we compare it to first snapshot we then know it was executed `2` times not `1002`.**\r\n\r\nSo in summary:\r\n* metric1 - skipped, can't be generated from one snapshot\r\n* metric2:\r\n  * Query `1` SUM: `1`\r\n* metric3:\r\n  * Query `1` SUM: `1`\r\n  * **Query `1` SUM: `1002` but it should be `2`**\r\n\r\n\r\n# Fix\r\n\r\nReplicate `events_statements_summary_by_digest` table.\r\n\r\nOn `performance schema collector`/`qan-agent` start we could scrap whole `events_statements_summary_by_digest` table and store it in-memory or locally, and when comparing new snapshots to it we should update it at the end with new values.\r\n\r\n```\r\ntake `base snapshot` of whole `events_statements_summary_by_digest` table\r\nfor {\r\n  take `interval snapshot`\r\n  compare `interval snapshot` to `base snapshot` and generate difference as metrics\r\n  update `base snapshot` (e.g. with values from `interval snapshot`) \\\r\n      to sync it with `events_statements_summary_by_digest` table\r\n}\r\n```"},"comment":{"url":"https://api.github.com/repos/percona/qan-agent/issues/comments/316097369","html_url":"https://github.com/percona/qan-agent/pull/53#issuecomment-316097369","issue_url":"https://api.github.com/repos/percona/qan-agent/issues/53","id":316097369,"user":{"login":"arvenil","id":450355,"avatar_url":"https://avatars0.githubusercontent.com/u/450355?v=4","gravatar_id":"","url":"https://api.github.com/users/arvenil","html_url":"https://github.com/arvenil","followers_url":"https://api.github.com/users/arvenil/followers","following_url":"https://api.github.com/users/arvenil/following{/other_user}","gists_url":"https://api.github.com/users/arvenil/gists{/gist_id}","starred_url":"https://api.github.com/users/arvenil/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/arvenil/subscriptions","organizations_url":"https://api.github.com/users/arvenil/orgs","repos_url":"https://api.github.com/users/arvenil/repos","events_url":"https://api.github.com/users/arvenil/events{/privacy}","received_events_url":"https://api.github.com/users/arvenil/received_events","type":"User","site_admin":false},"created_at":"2017-07-18T15:16:45Z","updated_at":"2017-07-18T15:16:45Z","body":"@AlekSi If you have time and wish, could you review this PR? This is one of the most separate part of the agent and it's not so complex. I think it's a good starting point to understand some of the agent parts and it would be nice to get third point of view for qan-agent."}}
{"actor":{"display_login":"arvenil"}}