{"action":"created","issue":{"url":"https://api.github.com/repos/saltstack/salt/issues/36720","repository_url":"https://api.github.com/repos/saltstack/salt","labels_url":"https://api.github.com/repos/saltstack/salt/issues/36720/labels{/name}","comments_url":"https://api.github.com/repos/saltstack/salt/issues/36720/comments","events_url":"https://api.github.com/repos/saltstack/salt/issues/36720/events","html_url":"https://github.com/saltstack/salt/pull/36720","id":180377553,"number":36720,"title":"Fix race condition when returning events from commands","user":{"login":"skizunov","id":11562452,"avatar_url":"https://avatars.githubusercontent.com/u/11562452?v=3","gravatar_id":"","url":"https://api.github.com/users/skizunov","html_url":"https://github.com/skizunov","followers_url":"https://api.github.com/users/skizunov/followers","following_url":"https://api.github.com/users/skizunov/following{/other_user}","gists_url":"https://api.github.com/users/skizunov/gists{/gist_id}","starred_url":"https://api.github.com/users/skizunov/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/skizunov/subscriptions","organizations_url":"https://api.github.com/users/skizunov/orgs","repos_url":"https://api.github.com/users/skizunov/repos","events_url":"https://api.github.com/users/skizunov/events{/privacy}","received_events_url":"https://api.github.com/users/skizunov/received_events","type":"User","site_admin":false},"labels":[],"state":"open","locked":false,"assignee":null,"assignees":[],"milestone":null,"comments":1,"created_at":"2016-09-30T18:57:35Z","updated_at":"2016-10-04T05:56:03Z","closed_at":null,"pull_request":{"url":"https://api.github.com/repos/saltstack/salt/pulls/36720","html_url":"https://github.com/saltstack/salt/pull/36720","diff_url":"https://github.com/saltstack/salt/pull/36720.diff","patch_url":"https://github.com/saltstack/salt/pull/36720.patch"},"body":"### What does this PR do?\r\n\r\nIt has been observed that when running this command:\r\n\r\n```\r\nsalt \"*\" test.ping\r\n```\r\n\r\nsometimes the command would return `Minion did not return. [No response]`\r\nfor some of the minions even though the minions did indeed respond\r\n(reproduced running Windows salt-master on Python 3 using the TCP\r\ntransport).\r\n\r\nAfter investigating this further, it seems that there is a race condition\r\nwhere if the response via event happens before events are being listened\r\nfor, the response is lost. For instance, in\r\n`salt.client.LocalClient.cmd_cli` which is what is invoked in the command\r\nabove, it won't start listening for events until `get_cli_event_returns`\r\nwhich invokes `get_iter_returns` which invokes `get_returns_no_block`\r\nwhich invokes `self.event.get_event` which will connect to the event bus\r\nif it hasn't connected yet (which is the case the first time it hits\r\nthis code). But events may be fired anytime after `self.pub()` is\r\nexecuted which occurs before this code.\r\n\r\nWe need to ensure that events are being listened for before it is\r\npossible they return. We also want to avoid issue #31454 which is what\r\nPR #36024 fixed but in turn caused this issue. This is the approach I\r\nhave taken to try to tackle this issue:\r\n\r\nIt doesn't seem possible to generically discern if events can be\r\nreturned by a given function that invokes `run_job` and contains an\r\nevent searching function such as `get_cli_event_returns`. So for all\r\nsuch functions that could possibly need to search the event bus, we\r\ndo the following:\r\n- Record if the event bus is currently being listened to.\r\n- When invoking `run_job`, ensure that `listen=True` so that `self.pub()`\r\nwill ensure that the event bus is listed to before sending the payload.\r\n- When all possible event bus activities are concluded, if the event\r\nbus was not originally being listened to, stop listening to it. This is\r\ndesigned so that issue #31454 does not reappear. We do this via a\r\ntry/finally block in all instances of such code.\r\n\r\n### Tests written?\r\n\r\nNo\r\n\r\nSigned-off-by: Sergey Kizunov <sergey.kizunov@ni.com>"},"comment":{"url":"https://api.github.com/repos/saltstack/salt/issues/comments/251302683","html_url":"https://github.com/saltstack/salt/pull/36720#issuecomment-251302683","issue_url":"https://api.github.com/repos/saltstack/salt/issues/36720","id":251302683,"user":{"login":"skizunov","id":11562452,"avatar_url":"https://avatars.githubusercontent.com/u/11562452?v=3","gravatar_id":"","url":"https://api.github.com/users/skizunov","html_url":"https://github.com/skizunov","followers_url":"https://api.github.com/users/skizunov/followers","following_url":"https://api.github.com/users/skizunov/following{/other_user}","gists_url":"https://api.github.com/users/skizunov/gists{/gist_id}","starred_url":"https://api.github.com/users/skizunov/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/skizunov/subscriptions","organizations_url":"https://api.github.com/users/skizunov/orgs","repos_url":"https://api.github.com/users/skizunov/repos","events_url":"https://api.github.com/users/skizunov/events{/privacy}","received_events_url":"https://api.github.com/users/skizunov/received_events","type":"User","site_admin":false},"created_at":"2016-10-04T05:56:03Z","updated_at":"2016-10-04T05:56:03Z","body":"@cachedout : I added a fix and now there is only 1 test failure, and only on `salt-pr-linode-ubuntu14-n`. It looks like this:\r\n\r\n```\r\n05:23:37 ======================================================================\r\n05:23:37 ERROR [2.061s]: test_badload (unit.transport.zeromq_test.AESReqTestCases)\r\n05:23:37 [CPU:1.2%|MEM:45.7%|Z:0] \r\n05:23:37 ----------------------------------------------------------------------\r\n05:23:37 Traceback (most recent call last):\r\n05:23:37   File \"/testing/tests/unit/transport/zeromq_test.py\", line 132, in test_badload\r\n05:23:37     ret = self.channel.send(msg, timeout=1)\r\n05:23:37   File \"/testing/salt/utils/async.py\", line 75, in wrap\r\n05:23:37     ret = self._block_future(ret)\r\n05:23:37   File \"/testing/salt/utils/async.py\", line 84, in _block_future\r\n05:23:37     self.io_loop.start()\r\n05:23:37   File \"/usr/lib/python2.7/dist-packages/zmq/eventloop/ioloop.py\", line 157, in start\r\n05:23:37     raise e\r\n05:23:37 ZMQError: Socket operation on non-socket\r\n05:23:37 \r\n05:23:37 ----------------------------------------------------------------------\r\n```\r\n\r\nDo you think this is related to the changes in this PR or is external to these changes?"}}
{"actor":{"display_login":"skizunov"}}