{"action":"created","issue":{"url":"https://api.github.com/repos/cylc/cylc/issues/872","labels_url":"https://api.github.com/repos/cylc/cylc/issues/872/labels{/name}","comments_url":"https://api.github.com/repos/cylc/cylc/issues/872/comments","events_url":"https://api.github.com/repos/cylc/cylc/issues/872/events","html_url":"https://github.com/cylc/cylc/issues/872","id":26495506,"number":872,"title":"Strange polling result","user":{"login":"hjoliver","id":2362137,"avatar_url":"https://avatars.githubusercontent.com/u/2362137?v=3","gravatar_id":"","url":"https://api.github.com/users/hjoliver","html_url":"https://github.com/hjoliver","followers_url":"https://api.github.com/users/hjoliver/followers","following_url":"https://api.github.com/users/hjoliver/following{/other_user}","gists_url":"https://api.github.com/users/hjoliver/gists{/gist_id}","starred_url":"https://api.github.com/users/hjoliver/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/hjoliver/subscriptions","organizations_url":"https://api.github.com/users/hjoliver/orgs","repos_url":"https://api.github.com/users/hjoliver/repos","events_url":"https://api.github.com/users/hjoliver/events{/privacy}","received_events_url":"https://api.github.com/users/hjoliver/received_events","type":"User","site_admin":false},"labels":[],"state":"closed","locked":false,"assignee":{"login":"hjoliver","id":2362137,"avatar_url":"https://avatars.githubusercontent.com/u/2362137?v=3","gravatar_id":"","url":"https://api.github.com/users/hjoliver","html_url":"https://github.com/hjoliver","followers_url":"https://api.github.com/users/hjoliver/followers","following_url":"https://api.github.com/users/hjoliver/following{/other_user}","gists_url":"https://api.github.com/users/hjoliver/gists{/gist_id}","starred_url":"https://api.github.com/users/hjoliver/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/hjoliver/subscriptions","organizations_url":"https://api.github.com/users/hjoliver/orgs","repos_url":"https://api.github.com/users/hjoliver/repos","events_url":"https://api.github.com/users/hjoliver/events{/privacy}","received_events_url":"https://api.github.com/users/hjoliver/received_events","type":"User","site_admin":false},"milestone":{"url":"https://api.github.com/repos/cylc/cylc/milestones/5","labels_url":"https://api.github.com/repos/cylc/cylc/milestones/5/labels","id":262614,"number":5,"title":"soon","description":"A few months in the future. Top priority issues and easy fixes should initially be marked against this milestone, and then moved to *next-release* if work progresses quickly enough.","creator":{"login":"hjoliver","id":2362137,"avatar_url":"https://avatars.githubusercontent.com/u/2362137?v=3","gravatar_id":"","url":"https://api.github.com/users/hjoliver","html_url":"https://github.com/hjoliver","followers_url":"https://api.github.com/users/hjoliver/followers","following_url":"https://api.github.com/users/hjoliver/following{/other_user}","gists_url":"https://api.github.com/users/hjoliver/gists{/gist_id}","starred_url":"https://api.github.com/users/hjoliver/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/hjoliver/subscriptions","organizations_url":"https://api.github.com/users/hjoliver/orgs","repos_url":"https://api.github.com/users/hjoliver/repos","events_url":"https://api.github.com/users/hjoliver/events{/privacy}","received_events_url":"https://api.github.com/users/hjoliver/received_events","type":"User","site_admin":false},"open_issues":50,"closed_issues":2,"state":"open","created_at":"2013-02-08T07:07:13Z","updated_at":"2015-02-11T02:46:40Z","due_on":"2015-03-31T07:00:00Z","closed_at":null},"comments":7,"created_at":"2014-01-29T03:05:45Z","updated_at":"2015-02-11T02:46:40Z","closed_at":"2015-02-11T02:46:40Z","body":"From Yi Xiao, the following suite log shows 60 second polling that repeatedly reports a task still running, then 30s after the task succeededs it polls failed once, which unfortunately puts the task in the failed state, then it polls succeeded.  The polls must be taking a while to complete and have backed up, but the single failed result is odd.\r\n\r\n@matthewrmshin - any ideas?  The task is apparently an OPS Rose app.  I presume OPS jobs do not still complete via scripting submitted internally via ```at now``` (opsui jobs do this) which could result in them polling as failed briefly.\r\n\r\n```\r\n2014/01/26 10:25:59 INFO - [Ops_radwind.2013112312] -Task host: raijin6.nci.org.au\r\n2014/01/26 10:25:59 INFO - [Ops_radwind.2013112312] -(current:ready)> Ops_radwind.2013112312 submitting now\r\n2014/01/26 10:26:14 INFO - [Ops_radwind.2013112312] -(current:ready)> Ops_radwind.2013112312 submission succeeded\r\n2014/01/26 10:26:14 INFO - [Ops_radwind.2013112312] -(current:submitted)> Ops_radwind.2013112312 submit_method_id=2158622.r-man2\r\n2014/01/26 10:26:33 INFO - [Ops_radwind.2013112312] -(current:submitted)> Ops_radwind.2013112312 started at 2014-01-26T10:26:33\r\n2014/01/26 10:26:33 INFO - [Ops_radwind.2013112312] -setting execution poll timer for 60.0 seconds\r\n2014/01/26 10:27:33 INFO - [Ops_radwind.2013112312] -polling now\r\n2014/01/26 10:27:33 INFO - [Ops_radwind.2013112312] -setting execution poll timer for 60.0 seconds\r\n2014/01/26 10:27:36 INFO - [Ops_radwind.2013112312] -(current:running)> polled Ops_radwind.2013112312 started at 2014-01-25T23:26:33\r\n2014/01/26 10:28:33 INFO - [Ops_radwind.2013112312] -polling now\r\n2014/01/26 10:28:33 INFO - [Ops_radwind.2013112312] -setting execution poll timer for 60.0 seconds\r\n2014/01/26 10:28:38 INFO - [Ops_radwind.2013112312] -(current:running)> polled Ops_radwind.2013112312 started at 2014-01-25T23:26:33\r\n2014/01/26 10:29:34 INFO - [Ops_radwind.2013112312] -polling now\r\n2014/01/26 10:29:34 INFO - [Ops_radwind.2013112312] -setting execution poll timer for 60.0 seconds\r\n2014/01/26 10:29:45 INFO - [Ops_radwind.2013112312] -(current:running)> polled Ops_radwind.2013112312 started at 2014-01-25T23:26:33\r\n2014/01/26 10:30:35 INFO - [Ops_radwind.2013112312] -polling now\r\n2014/01/26 10:30:35 INFO - [Ops_radwind.2013112312] -setting execution poll timer for 60.0 seconds\r\n2014/01/26 10:30:45 INFO - [Ops_radwind.2013112312] -(current:running)> polled Ops_radwind.2013112312 started at 2014-01-25T23:26:33\r\n2014/01/26 10:31:35 INFO - [Ops_radwind.2013112312] -polling now\r\n2014/01/26 10:31:35 INFO - [Ops_radwind.2013112312] -setting execution poll timer for 60.0 seconds\r\n2014/01/26 10:32:35 INFO - [Ops_radwind.2013112312] -polling now\r\n2014/01/26 10:32:35 INFO - [Ops_radwind.2013112312] -setting execution poll timer for 60.0 seconds\r\n2014/01/26 10:33:28 INFO - [Ops_radwind.2013112312] -(current:running)> polled Ops_radwind.2013112312 started at 2014-01-25T23:26:33\r\n2014/01/26 10:33:36 INFO - [Ops_radwind.2013112312] -polling now\r\n2014/01/26 10:33:36 INFO - [Ops_radwind.2013112312] -setting execution poll timer for 60.0 seconds\r\n2014/01/26 10:33:42 INFO - [Ops_radwind.2013112312] -(current:running)> polled Ops_radwind.2013112312 started at 2014-01-25T23:26:33\r\n2014/01/26 10:33:50 INFO - [Ops_radwind.2013112312] -(current:running)> polled Ops_radwind.2013112312 started at 2014-01-25T23:26:33\r\n2014/01/26 10:34:36 INFO - [Ops_radwind.2013112312] -polling now\r\n2014/01/26 10:34:36 INFO - [Ops_radwind.2013112312] -setting execution poll timer for 60.0 seconds\r\n2014/01/26 10:34:41 INFO - [Ops_radwind.2013112312] -(current:running)> polled Ops_radwind.2013112312 started at 2014-01-25T23:26:33\r\n2014/01/26 10:35:36 INFO - [Ops_radwind.2013112312] -polling now\r\n2014/01/26 10:35:36 INFO - [Ops_radwind.2013112312] -setting execution poll timer for 60.0 seconds\r\n2014/01/26 10:35:39 INFO - [Ops_radwind.2013112312] -(current:running)> polled Ops_radwind.2013112312 started at 2014-01-25T23:26:33\r\n2014/01/26 10:36:37 INFO - [Ops_radwind.2013112312] -polling now\r\n2014/01/26 10:36:37 INFO - [Ops_radwind.2013112312] -setting execution poll timer for 60.0 seconds\r\n2014/01/26 10:36:41 INFO - [Ops_radwind.2013112312] -(current:running)> polled Ops_radwind.2013112312 started at 2014-01-25T23:26:33\r\n2014/01/26 10:37:37 INFO - [Ops_radwind.2013112312] -polling now\r\n2014/01/26 10:37:37 INFO - [Ops_radwind.2013112312] -setting execution poll timer for 60.0 seconds\r\n2014/01/26 10:37:41 INFO - [Ops_radwind.2013112312] -(current:running)> polled Ops_radwind.2013112312 started at 2014-01-25T23:26:33\r\n2014/01/26 10:38:37 INFO - [Ops_radwind.2013112312] -polling now\r\n2014/01/26 10:38:37 INFO - [Ops_radwind.2013112312] -setting execution poll timer for 60.0 seconds\r\n2014/01/26 10:38:40 INFO - [Ops_radwind.2013112312] -(current:running)> polled Ops_radwind.2013112312 started at 2014-01-25T23:26:33\r\n2014/01/26 10:39:38 INFO - [Ops_radwind.2013112312] -polling now\r\n2014/01/26 10:39:38 INFO - [Ops_radwind.2013112312] -setting execution poll timer for 60.0 seconds\r\n2014/01/26 10:39:38 INFO - [Ops_radwind.2013112312] -setting execution poll timer for 60.0 seconds\r\n2014/01/26 10:40:32 INFO - [Ops_radwind.2013112312] -(current:running)> polled Ops_radwind.2013112312 started at 2014-01-25T23:26:33\r\n2014/01/26 10:40:38 INFO - [Ops_radwind.2013112312] -polling now\r\n2014/01/26 10:40:38 INFO - [Ops_radwind.2013112312] -setting execution poll timer for 60.0 seconds\r\n2014/01/26 10:41:38 INFO - [Ops_radwind.2013112312] -polling now\r\n2014/01/26 10:41:38 INFO - [Ops_radwind.2013112312] -setting execution poll timer for 60.0 seconds\r\n2014/01/26 10:41:48 INFO - [Ops_radwind.2013112312] -(current:running)> polled Ops_radwind.2013112312 started at 2014-01-25T23:26:33\r\n2014/01/26 10:42:39 INFO - [Ops_radwind.2013112312] -polling now\r\n2014/01/26 10:42:39 INFO - [Ops_radwind.2013112312] -setting execution poll timer for 60.0 seconds\r\n2014/01/26 10:43:25 INFO - [Ops_radwind.2013112312] -(current:running)> Ops_radwind.2013112312 succeeded at 2014-01-26T10:43:24\r\n2014/01/26 10:43:54 INFO - [Ops_radwind.2013112312] -(current:succeeded)> polled Ops_radwind.2013112312 failed at unknown-time\r\n2014/01/26 10:44:27 INFO - [Ops_radwind.2013112312] -(current:failed)> polled Ops_radwind.2013112312 succeeded at 2014-01-25T23:43:25\r\n2014/01/26 10:44:27 WARNING - [Ops_radwind.2013112312] -rejecting a message received while in the failed state:\r\n2014/01/26 10:44:27 WARNING - [Ops_radwind.2013112312] -  polled Ops_radwind.2013112312 succeeded at 2014-01-25T23:43:25\r\n```\r\n\r\n"},"comment":{"url":"https://api.github.com/repos/cylc/cylc/issues/comments/73826261","html_url":"https://github.com/cylc/cylc/issues/872#issuecomment-73826261","issue_url":"https://api.github.com/repos/cylc/cylc/issues/872","id":73826261,"user":{"login":"hjoliver","id":2362137,"avatar_url":"https://avatars.githubusercontent.com/u/2362137?v=3","gravatar_id":"","url":"https://api.github.com/users/hjoliver","html_url":"https://github.com/hjoliver","followers_url":"https://api.github.com/users/hjoliver/followers","following_url":"https://api.github.com/users/hjoliver/following{/other_user}","gists_url":"https://api.github.com/users/hjoliver/gists{/gist_id}","starred_url":"https://api.github.com/users/hjoliver/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/hjoliver/subscriptions","organizations_url":"https://api.github.com/users/hjoliver/orgs","repos_url":"https://api.github.com/users/hjoliver/repos","events_url":"https://api.github.com/users/hjoliver/events{/privacy}","received_events_url":"https://api.github.com/users/hjoliver/received_events","type":"User","site_admin":false},"created_at":"2015-02-11T02:46:40Z","updated_at":"2015-02-11T02:46:40Z","body":"Closing - this is now a year old; it resulted in one change #880; and I've had no further reports of problems."}}