{"action":"created","issue":{"url":"https://api.github.com/repos/pingcap/tidb/issues/7044","repository_url":"https://api.github.com/repos/pingcap/tidb","labels_url":"https://api.github.com/repos/pingcap/tidb/issues/7044/labels{/name}","comments_url":"https://api.github.com/repos/pingcap/tidb/issues/7044/comments","events_url":"https://api.github.com/repos/pingcap/tidb/issues/7044/events","html_url":"https://github.com/pingcap/tidb/issues/7044","id":340698948,"node_id":"MDU6SXNzdWUzNDA2OTg5NDg=","number":7044,"title":"need to change TIME_COP_PROCESS to TIME_COP_WAIT","user":{"login":"zz-jason","id":5268763,"node_id":"MDQ6VXNlcjUyNjg3NjM=","avatar_url":"https://avatars0.githubusercontent.com/u/5268763?v=4","gravatar_id":"","url":"https://api.github.com/users/zz-jason","html_url":"https://github.com/zz-jason","followers_url":"https://api.github.com/users/zz-jason/followers","following_url":"https://api.github.com/users/zz-jason/following{/other_user}","gists_url":"https://api.github.com/users/zz-jason/gists{/gist_id}","starred_url":"https://api.github.com/users/zz-jason/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/zz-jason/subscriptions","organizations_url":"https://api.github.com/users/zz-jason/orgs","repos_url":"https://api.github.com/users/zz-jason/repos","events_url":"https://api.github.com/users/zz-jason/events{/privacy}","received_events_url":"https://api.github.com/users/zz-jason/received_events","type":"User","site_admin":false},"labels":[{"id":970807266,"node_id":"MDU6TGFiZWw5NzA4MDcyNjY=","url":"https://api.github.com/repos/pingcap/tidb/labels/component/executor","name":"component/executor","color":"000000","default":false},{"id":586074134,"node_id":"MDU6TGFiZWw1ODYwNzQxMzQ=","url":"https://api.github.com/repos/pingcap/tidb/labels/for%20new%20contributors","name":"for new contributors","color":"c2e0c6","default":false},{"id":256872089,"node_id":"MDU6TGFiZWwyNTY4NzIwODk=","url":"https://api.github.com/repos/pingcap/tidb/labels/help%20wanted","name":"help wanted","color":"159818","default":true},{"id":256872088,"node_id":"MDU6TGFiZWwyNTY4NzIwODg=","url":"https://api.github.com/repos/pingcap/tidb/labels/type/enhancement","name":"type/enhancement","color":"84b6eb","default":false}],"state":"open","locked":false,"assignee":null,"assignees":[],"milestone":{"url":"https://api.github.com/repos/pingcap/tidb/milestones/11","html_url":"https://github.com/pingcap/tidb/milestone/11","labels_url":"https://api.github.com/repos/pingcap/tidb/milestones/11/labels","id":3254588,"node_id":"MDk6TWlsZXN0b25lMzI1NDU4OA==","number":11,"title":"2.1","description":"","creator":{"login":"shenli","id":1192573,"node_id":"MDQ6VXNlcjExOTI1NzM=","avatar_url":"https://avatars0.githubusercontent.com/u/1192573?v=4","gravatar_id":"","url":"https://api.github.com/users/shenli","html_url":"https://github.com/shenli","followers_url":"https://api.github.com/users/shenli/followers","following_url":"https://api.github.com/users/shenli/following{/other_user}","gists_url":"https://api.github.com/users/shenli/gists{/gist_id}","starred_url":"https://api.github.com/users/shenli/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/shenli/subscriptions","organizations_url":"https://api.github.com/users/shenli/orgs","repos_url":"https://api.github.com/users/shenli/repos","events_url":"https://api.github.com/users/shenli/events{/privacy}","received_events_url":"https://api.github.com/users/shenli/received_events","type":"User","site_admin":false},"open_issues":8,"closed_issues":21,"state":"open","created_at":"2018-04-10T03:42:16Z","updated_at":"2018-07-12T15:55:24Z","due_on":"2018-07-31T07:00:00Z","closed_at":null},"comments":0,"created_at":"2018-07-12T15:55:24Z","updated_at":"2018-07-13T00:42:51Z","closed_at":null,"author_association":"MEMBER","body":"Take this log as an example:\r\n```sql\r\n2018/07/12 23:40:03.287 coprocessor.go:689: [info] [TIME_COP_PROCESS] resp_time:11.9717251s txn_start_ts:401449940753055943 region_id:2 store_addr:10.0.1.5:20160 kv_process_ms:1702 scan_total_write:692145 scan_processed_write:692144 scan_total_data:0 scan_processed_data:0 scan_total_lock:1 scan_processed_lock:0 kv_wait_ms:10264\r\n```\r\n\r\n- `kv_wait_ms`: 10264ms\r\n- `kv_process_ms`: 1702ms\r\n\r\n`kv_wait_ms` is far more larger than `kv_process_ms` and this slow coprocessor task is mainly caused by the wait, but we still printed the `TIME_COP_PROCESS`.\r\n\r\nThe source code to log this entry is here in file **store/tikv/coprocessor.go**:\r\n```go\r\n659         if waitMs > minLogKVWaitTime {\r\n660             logStr += fmt.Sprintf(\" kv_wait_ms:%d\", waitMs)\r\n661             if processMs <= minLogKVProcessTime {\r\n662                 logStr = strings.Replace(logStr, \"TIME_COP_PROCESS\", \"TIME_COP_WAIT\", 1)\r\n663             }\r\n664         }\r\n```\r\n\r\nWe should change `TIME_COP_PROCESS` to `TIME_COP_WAIT` when `kv_wait_ms` > `kv_process_ms`\r\n"},"comment":{"url":"https://api.github.com/repos/pingcap/tidb/issues/comments/404692076","html_url":"https://github.com/pingcap/tidb/issues/7044#issuecomment-404692076","issue_url":"https://api.github.com/repos/pingcap/tidb/issues/7044","id":404692076,"node_id":"MDEyOklzc3VlQ29tbWVudDQwNDY5MjA3Ng==","user":{"login":"coocood","id":891222,"node_id":"MDQ6VXNlcjg5MTIyMg==","avatar_url":"https://avatars0.githubusercontent.com/u/891222?v=4","gravatar_id":"","url":"https://api.github.com/users/coocood","html_url":"https://github.com/coocood","followers_url":"https://api.github.com/users/coocood/followers","following_url":"https://api.github.com/users/coocood/following{/other_user}","gists_url":"https://api.github.com/users/coocood/gists{/gist_id}","starred_url":"https://api.github.com/users/coocood/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/coocood/subscriptions","organizations_url":"https://api.github.com/users/coocood/orgs","repos_url":"https://api.github.com/users/coocood/repos","events_url":"https://api.github.com/users/coocood/events{/privacy}","received_events_url":"https://api.github.com/users/coocood/received_events","type":"User","site_admin":false},"created_at":"2018-07-13T00:42:51Z","updated_at":"2018-07-13T00:42:51Z","author_association":"MEMBER","body":"but what if all process slow is mainly caused by wait？we may have no TIME_COP_PROCESS label in the log."}}
{"actor":{"display_login":"coocood"}}