{"action":"created","issue":{"url":"https://api.github.com/repos/GoogleCloudPlatform/google-cloud-node/issues/2572","repository_url":"https://api.github.com/repos/GoogleCloudPlatform/google-cloud-node","labels_url":"https://api.github.com/repos/GoogleCloudPlatform/google-cloud-node/issues/2572/labels{/name}","comments_url":"https://api.github.com/repos/GoogleCloudPlatform/google-cloud-node/issues/2572/comments","events_url":"https://api.github.com/repos/GoogleCloudPlatform/google-cloud-node/issues/2572/events","html_url":"https://github.com/GoogleCloudPlatform/google-cloud-node/issues/2572","id":253192595,"number":2572,"title":"PubSub locks up Node process at 100% CPU","user":{"login":"ehacke","id":4016786,"avatar_url":"https://avatars2.githubusercontent.com/u/4016786?v=4","gravatar_id":"","url":"https://api.github.com/users/ehacke","html_url":"https://github.com/ehacke","followers_url":"https://api.github.com/users/ehacke/followers","following_url":"https://api.github.com/users/ehacke/following{/other_user}","gists_url":"https://api.github.com/users/ehacke/gists{/gist_id}","starred_url":"https://api.github.com/users/ehacke/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/ehacke/subscriptions","organizations_url":"https://api.github.com/users/ehacke/orgs","repos_url":"https://api.github.com/users/ehacke/repos","events_url":"https://api.github.com/users/ehacke/events{/privacy}","received_events_url":"https://api.github.com/users/ehacke/received_events","type":"User","site_admin":false},"labels":[{"id":168217155,"url":"https://api.github.com/repos/GoogleCloudPlatform/google-cloud-node/labels/api:%20pubsub","name":"api: pubsub","color":"cd7f32","default":false},{"id":544179613,"url":"https://api.github.com/repos/GoogleCloudPlatform/google-cloud-node/labels/priority:%20p1","name":"priority: p1","color":"ffa03e","default":false},{"id":97433036,"url":"https://api.github.com/repos/GoogleCloudPlatform/google-cloud-node/labels/type:%20bug","name":"type: bug","color":"db4437","default":false}],"state":"open","locked":false,"assignee":{"login":"callmehiphop","id":1707267,"avatar_url":"https://avatars3.githubusercontent.com/u/1707267?v=4","gravatar_id":"","url":"https://api.github.com/users/callmehiphop","html_url":"https://github.com/callmehiphop","followers_url":"https://api.github.com/users/callmehiphop/followers","following_url":"https://api.github.com/users/callmehiphop/following{/other_user}","gists_url":"https://api.github.com/users/callmehiphop/gists{/gist_id}","starred_url":"https://api.github.com/users/callmehiphop/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/callmehiphop/subscriptions","organizations_url":"https://api.github.com/users/callmehiphop/orgs","repos_url":"https://api.github.com/users/callmehiphop/repos","events_url":"https://api.github.com/users/callmehiphop/events{/privacy}","received_events_url":"https://api.github.com/users/callmehiphop/received_events","type":"User","site_admin":false},"assignees":[{"login":"callmehiphop","id":1707267,"avatar_url":"https://avatars3.githubusercontent.com/u/1707267?v=4","gravatar_id":"","url":"https://api.github.com/users/callmehiphop","html_url":"https://github.com/callmehiphop","followers_url":"https://api.github.com/users/callmehiphop/followers","following_url":"https://api.github.com/users/callmehiphop/following{/other_user}","gists_url":"https://api.github.com/users/callmehiphop/gists{/gist_id}","starred_url":"https://api.github.com/users/callmehiphop/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/callmehiphop/subscriptions","organizations_url":"https://api.github.com/users/callmehiphop/orgs","repos_url":"https://api.github.com/users/callmehiphop/repos","events_url":"https://api.github.com/users/callmehiphop/events{/privacy}","received_events_url":"https://api.github.com/users/callmehiphop/received_events","type":"User","site_admin":false}],"milestone":null,"comments":10,"created_at":"2017-08-27T21:55:41Z","updated_at":"2017-08-31T15:29:59Z","closed_at":null,"author_association":"NONE","body":"#### Environment details\r\n\r\n  - OS: Linux Mint 18.2 (dev) \r\n  - Node.js version: 8.3.0\r\n  - npm version: 5.3.0\r\n  - @google-cloud/pubsub version: 0.13.2 and 0.14\r\n\r\n#### Steps to reproduce\r\n\r\n  1.Try to read from PubSub subscription (even if it's completely empty)\r\n  2. Node process goes to 100% of CPU and eventually is killed by K8S\r\n  3. Apologize for not having any good reproduction steps\r\n\r\nSo we've been having intermittent issues with reading from subscriptions attached to one specific topic using Node. The same code will run fine for weeks, and then suddenly every Node process attached to that subscription is pegged to 100% CPU until the process is killed externally. The crazy part is that even after the subscription is completely drained, this continues to happen. There is nothing to read, and yet it's completely locked up. It will continue to lock up every process attached to it for days, then suddenly stop.\r\n\r\nI completely agree that this sounds like an implementation issue on my side, but hear me out.\r\n\r\nImportant details:.\r\n- It does not seem to matter if there is anything in the subscription. An empty subscription also locks up the reading process.\r\n- Running a flamegraph analysis (attached) shows that 97.18% of the time, some function called Node::MakeCallback is on the top of the stack. In my mind this points to the GPRC library being involved in the problem.\r\n- The same application code functions fine using Kafka as the queue, with the only difference being the very simple read and write operations.\r\n- Other Node applications, written significantly differently, also attached to subscriptions on that topic will also fail in the same way, but at different times. Which suggests to me that it's not an issue with the content of the subscriptions (it can even be empty), but the operation of reading from the subscription itself.\r\n- We have many many other Node processes, using the same reading and writing code, connected to different topics, that never experience this issue.\r\n- If it helps, another unique detail is that the source of this topic is our only Dataflow process\r\n\r\nIs there anything else I can do to try to trace this problem? \r\n\r\nI accept that I haven't given enough info for this be resolvable on your side, but I'm at a loss on how to debug this further.\r\n\r\n![makecallback](https://user-images.githubusercontent.com/4016786/29754334-d3f5508a-8b50-11e7-8135-222d6f2618cb.png)\r\n\r\n"},"comment":{"url":"https://api.github.com/repos/GoogleCloudPlatform/google-cloud-node/issues/comments/326332173","html_url":"https://github.com/GoogleCloudPlatform/google-cloud-node/issues/2572#issuecomment-326332173","issue_url":"https://api.github.com/repos/GoogleCloudPlatform/google-cloud-node/issues/2572","id":326332173,"user":{"login":"ehacke","id":4016786,"avatar_url":"https://avatars2.githubusercontent.com/u/4016786?v=4","gravatar_id":"","url":"https://api.github.com/users/ehacke","html_url":"https://github.com/ehacke","followers_url":"https://api.github.com/users/ehacke/followers","following_url":"https://api.github.com/users/ehacke/following{/other_user}","gists_url":"https://api.github.com/users/ehacke/gists{/gist_id}","starred_url":"https://api.github.com/users/ehacke/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/ehacke/subscriptions","organizations_url":"https://api.github.com/users/ehacke/orgs","repos_url":"https://api.github.com/users/ehacke/repos","events_url":"https://api.github.com/users/ehacke/events{/privacy}","received_events_url":"https://api.github.com/users/ehacke/received_events","type":"User","site_admin":false},"created_at":"2017-08-31T15:29:59Z","updated_at":"2017-08-31T15:29:59Z","author_association":"NONE","body":"And again, the interesting thing from our side in this case is that once again the two apps that are reading from this topic are receiving the same data, and parsing it in the same way using schema-inspector in the same code, but one is pinned to 100% CPU and the other is not.\r\n\r\nMy personal theory is that it's either something in the PubSub client library that eating the CPU directly, or somehow the messages are being modified by the PubSub reader in a way that causes the validation to eat CPU. But neither of those are validated yet, so I'll let you know."}}
{"actor":{"display_login":"ehacke"}}