{"action":"created","issue":{"url":"https://api.github.com/repos/saltstack/salt/issues/10900","labels_url":"https://api.github.com/repos/saltstack/salt/issues/10900/labels{/name}","comments_url":"https://api.github.com/repos/saltstack/salt/issues/10900/comments","events_url":"https://api.github.com/repos/saltstack/salt/issues/10900/events","html_url":"https://github.com/saltstack/salt/issues/10900","id":28635704,"number":10900,"title":"timeouts when targeting by pillar","user":{"login":"ryepup","id":40441,"avatar_url":"https://avatars.githubusercontent.com/u/40441?v=3","gravatar_id":"","url":"https://api.github.com/users/ryepup","html_url":"https://github.com/ryepup","followers_url":"https://api.github.com/users/ryepup/followers","following_url":"https://api.github.com/users/ryepup/following{/other_user}","gists_url":"https://api.github.com/users/ryepup/gists{/gist_id}","starred_url":"https://api.github.com/users/ryepup/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/ryepup/subscriptions","organizations_url":"https://api.github.com/users/ryepup/orgs","repos_url":"https://api.github.com/users/ryepup/repos","events_url":"https://api.github.com/users/ryepup/events{/privacy}","received_events_url":"https://api.github.com/users/ryepup/received_events","type":"User","site_admin":false},"labels":[{"url":"https://api.github.com/repos/saltstack/salt/labels/Bug","name":"Bug","color":"e11d21"},{"url":"https://api.github.com/repos/saltstack/salt/labels/Cannot%20Reproduce","name":"Cannot Reproduce","color":"c7def8"},{"url":"https://api.github.com/repos/saltstack/salt/labels/Core","name":"Core","color":"fef2c0"},{"url":"https://api.github.com/repos/saltstack/salt/labels/High%20Severity","name":"High Severity","color":"ff9143"},{"url":"https://api.github.com/repos/saltstack/salt/labels/Multi-Master","name":"Multi-Master","color":"006b75"}],"state":"open","locked":false,"assignee":{"login":"cachedout","id":111616,"avatar_url":"https://avatars.githubusercontent.com/u/111616?v=3","gravatar_id":"","url":"https://api.github.com/users/cachedout","html_url":"https://github.com/cachedout","followers_url":"https://api.github.com/users/cachedout/followers","following_url":"https://api.github.com/users/cachedout/following{/other_user}","gists_url":"https://api.github.com/users/cachedout/gists{/gist_id}","starred_url":"https://api.github.com/users/cachedout/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/cachedout/subscriptions","organizations_url":"https://api.github.com/users/cachedout/orgs","repos_url":"https://api.github.com/users/cachedout/repos","events_url":"https://api.github.com/users/cachedout/events{/privacy}","received_events_url":"https://api.github.com/users/cachedout/received_events","type":"User","site_admin":false},"milestone":{"url":"https://api.github.com/repos/saltstack/salt/milestones/13","html_url":"https://github.com/saltstack/salt/milestones/Approved","labels_url":"https://api.github.com/repos/saltstack/salt/milestones/13/labels","id":9265,"number":13,"title":"Approved","description":"All issues that are ready to be worked on, both bugs and features.","creator":{"login":"thatch45","id":507599,"avatar_url":"https://avatars.githubusercontent.com/u/507599?v=3","gravatar_id":"","url":"https://api.github.com/users/thatch45","html_url":"https://github.com/thatch45","followers_url":"https://api.github.com/users/thatch45/followers","following_url":"https://api.github.com/users/thatch45/following{/other_user}","gists_url":"https://api.github.com/users/thatch45/gists{/gist_id}","starred_url":"https://api.github.com/users/thatch45/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/thatch45/subscriptions","organizations_url":"https://api.github.com/users/thatch45/orgs","repos_url":"https://api.github.com/users/thatch45/repos","events_url":"https://api.github.com/users/thatch45/events{/privacy}","received_events_url":"https://api.github.com/users/thatch45/received_events","type":"User","site_admin":false},"open_issues":2396,"closed_issues":2260,"state":"open","created_at":"2011-05-14T04:00:56Z","updated_at":"2015-07-09T13:39:22Z","due_on":null,"closed_at":null},"comments":47,"created_at":"2014-03-03T16:44:25Z","updated_at":"2015-07-09T15:40:00Z","closed_at":null,"body":"I'm running master 0.17.5 (the latest available for ubuntu via PPA),\r\nand having trouble targeting by pillar, and getting some inconsistent\r\nresults with 3 minions. All minions were installed at the same time,\r\nand all have these versions:\r\n\r\n               Salt: 0.17.5-52-g2d4772c\r\n             Python: 2.7.5 (default, May 15 2013, 22:44:16) [MSC v.1500 64 bit (AMD64)]\r\n             Jinja2: 2.7.1\r\n           M2Crypto: 0.21.1\r\n     msgpack-python: 0.4.0\r\n       msgpack-pure: Not Installed\r\n           pycrypto: 2.6\r\n             PyYAML: 3.10\r\n              PyZMQ: 13.1.0\r\n                ZMQ: 3.2.2\r\n\r\n## detective work\r\n\r\nSelecting by id works great:\r\n\r\n    $ time sudo salt -E '(ryanwin|strat|voting).*' test.ping -v\r\n    Executing job with jid 20140303094057244900\r\n    -------------------------------------------\r\n    \r\n    voting.acceleration.net:\r\n    True\r\n    stratussync.acceleration.net:\r\n    True\r\n    ryanwin7.acceleration.net:\r\n    True\r\n    \r\n    real    0m1.695s\r\n    user    0m0.253s\r\n    sys     0m0.103s\r\n\r\nWhen I try to select by pillar, the first returns quickly but the\r\nothers fail:\r\n\r\n    $ time sudo salt -I 'nscp:*' test.ping -v                     \r\n    Executing job with jid 20140303094255341834\r\n    -------------------------------------------\r\n    \r\n    ryanwin7.acceleration.net:\r\n        True\r\n    stratussync.acceleration.net:\r\n        Minion did not return\r\n    voting.acceleration.net:\r\n        Minion did not return\r\n    \r\n    real    0m10.525s\r\n    user    0m0.291s\r\n    sys     0m0.072s\r\n\r\nIf I up the timeout, I get the same result, but it takes longer. So it\r\nseems like I'm hitting the timeout somewhere.\r\n\r\n    ryepup@scruffy:~$ time sudo salt -I 'nscp:*' test.ping -v -t 15\r\n    Executing job with jid 20140303094349905445\r\n    -------------------------------------------\r\n    \r\n    ryanwin7.acceleration.net:\r\n        True\r\n    stratussync.acceleration.net:\r\n        Minion did not return\r\n    voting.acceleration.net:\r\n        Minion did not return\r\n    \r\n    real    0m19.523s\r\n    user    0m0.224s\r\n    sys     0m0.136s\r\n    $ time sudo salt -I 'nscp:*' test.ping -v -t 60\r\n    Executing job with jid 20140303094457264656\r\n    -------------------------------------------\r\n    \r\n    ryanwin7.acceleration.net:\r\n        True\r\n    stratussync.acceleration.net:\r\n        Minion did not return\r\n    voting.acceleration.net:\r\n        Minion did not return\r\n    \r\n    real    1m5.702s\r\n    user    0m0.290s\r\n    sys     0m0.098s\r\n    $ time sudo salt -I 'nscp:*' test.ping -v -t 300                \r\n    Executing job with jid 20140303094640755340\r\n    -------------------------------------------\r\n    \r\n    ryanwin7.acceleration.net:\r\n        True\r\n    stratussync.acceleration.net:\r\n        Minion did not return\r\n    voting.acceleration.net:\r\n        Minion did not return\r\n    \r\n    real    5m13.684s\r\n    user    0m0.266s\r\n    sys     0m0.123s\r\n\r\nLooking at `pillar` directly, we see another all three have the right pillar:\r\n\r\n    $ sudo salt -E '(ryanwin|strat|voting).*' pillar.item nscp\r\n    ryanwin7.acceleration.net:\r\n        ----------\r\n        nscp:\r\n            ----------\r\n            ifs:\r\n                ----------\r\n                private:\r\n                    Red Hat VirtIO Ethernet Adapter\r\n    voting.acceleration.net:\r\n        ----------\r\n        nscp:\r\n            ----------\r\n            aspnet:\r\n                True\r\n            ifs:\r\n                ----------\r\n                private:\r\n                    Intel(R) PRO/1000 MT Network Connection #3\r\n                public:\r\n                    Intel(R) PRO/1000 MT Network Connection\r\n            iis:\r\n                True\r\n            mssql:\r\n                MSSQL$SQLEXPRESS\r\n    stratussync.acceleration.net:\r\n        ----------\r\n        nscp:\r\n            ----------\r\n            aspnet:\r\n                True\r\n            ifs:\r\n                ----------\r\n                private:\r\n                    Intel(R) PRO/1000 MT Network Connection #2\r\n                public:\r\n                    Intel(R) PRO/1000 MT Network Connection\r\n            iis:\r\n                True\r\n            mssql:\r\n                MSSQL$SQLEXPRESS\r\n\r\nHowever, if we use `pillar.get` instead of `pillar.item`, then we get different results\r\n\r\n    $ sudo salt -E '(ryanwin|strat|voting).*' pillar.get nscp\r\n    voting.acceleration.net:\r\n        \r\n    stratussync.acceleration.net:\r\n        \r\n    ryanwin7.acceleration.net:\r\n        ----------\r\n        ifs:\r\n            ----------\r\n            private:\r\n                Red Hat VirtIO Ethernet Adapter\r\n    \r\n\r\nWe only see the `nscp` section for the minion that we can successfully\r\nping via pillar targeting. Running `saltutil.refresh_pillar` did not not fix this, but running `saltutil.sync_all` did, and then `pillar.get` matched `pillar.item` as I'd expect.\r\nI was really hopeful with `saltutil.refresh_pillar` would solve my problem, but after that I got the same ping timeouts after all the refreshing/syncing.\r\n\r\nThe failing minions have nothing fishy in their logs, the master has\r\nnothing fishy in it's logs, and all respond nicely if targeted by id.\r\n\r\nI turned up the log verbosity and restarted the minions, and now it\r\nworks as expected:\r\n\r\n    $ time sudo salt -I 'nscp:*' test.ping\r\n    ryanwin7.acceleration.net:\r\n        True\r\n    voting.acceleration.net:\r\n        True\r\n    stratussync.acceleration.net:\r\n        True\r\n    \r\n    real    0m0.459s\r\n    user    0m0.277s\r\n    sys     0m0.097s\r\n\r\n## summary\r\n\r\nIt seems like my minions didn't have the right pillar state. I saw inconsistent results between `pillar.get` and `pillar.item`, and those were not resolved with `saltutil.refresh_pillar`, but were resolved by `saltutil.sync_all`. Even after the `pillar.get` returned the right results, targeting by pillar still timed out.\r\n\r\nMy best guess is there's some cache on the minion side that didn't get cleared enough. When I asked my master to target by pillar, it used its up-to-date cache files to target my three minions, the published the command. All my minions got the message, and looked at the target spec to see if they should reply. One of my minions had up-to-date pillar data, saw it was targeted, and replied. Two of my minions had stale pillar data, and ignored the command. Sometime later my specified timeout was up, and master gave up hearing back from those two.\r\n\r\nAfter rebooting the minions, the bad cache was cleared, and all went well."},"comment":{"url":"https://api.github.com/repos/saltstack/salt/issues/comments/120038815","html_url":"https://github.com/saltstack/salt/issues/10900#issuecomment-120038815","issue_url":"https://api.github.com/repos/saltstack/salt/issues/10900","id":120038815,"user":{"login":"Akilesh1597","id":6169589,"avatar_url":"https://avatars.githubusercontent.com/u/6169589?v=3","gravatar_id":"","url":"https://api.github.com/users/Akilesh1597","html_url":"https://github.com/Akilesh1597","followers_url":"https://api.github.com/users/Akilesh1597/followers","following_url":"https://api.github.com/users/Akilesh1597/following{/other_user}","gists_url":"https://api.github.com/users/Akilesh1597/gists{/gist_id}","starred_url":"https://api.github.com/users/Akilesh1597/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/Akilesh1597/subscriptions","organizations_url":"https://api.github.com/users/Akilesh1597/orgs","repos_url":"https://api.github.com/users/Akilesh1597/repos","events_url":"https://api.github.com/users/Akilesh1597/events{/privacy}","received_events_url":"https://api.github.com/users/Akilesh1597/received_events","type":"User","site_admin":false},"created_at":"2015-07-09T15:40:00Z","updated_at":"2015-07-09T15:40:00Z","body":"No after a saltutil.sync_all. after a 'refresh_pillar' things are normal. "}}