{"action":"created","issue":{"url":"https://api.github.com/repos/eclipse/smarthome/issues/6456","repository_url":"https://api.github.com/repos/eclipse/smarthome","labels_url":"https://api.github.com/repos/eclipse/smarthome/issues/6456/labels{/name}","comments_url":"https://api.github.com/repos/eclipse/smarthome/issues/6456/comments","events_url":"https://api.github.com/repos/eclipse/smarthome/issues/6456/events","html_url":"https://github.com/eclipse/smarthome/issues/6456","id":377371459,"node_id":"MDU6SXNzdWUzNzczNzE0NTk=","number":6456,"title":"Timer#reschedule(AbstractInstant) doesn't work after timer has terminated","user":{"login":"evansj","id":4680,"node_id":"MDQ6VXNlcjQ2ODA=","avatar_url":"https://avatars0.githubusercontent.com/u/4680?v=4","gravatar_id":"","url":"https://api.github.com/users/evansj","html_url":"https://github.com/evansj","followers_url":"https://api.github.com/users/evansj/followers","following_url":"https://api.github.com/users/evansj/following{/other_user}","gists_url":"https://api.github.com/users/evansj/gists{/gist_id}","starred_url":"https://api.github.com/users/evansj/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/evansj/subscriptions","organizations_url":"https://api.github.com/users/evansj/orgs","repos_url":"https://api.github.com/users/evansj/repos","events_url":"https://api.github.com/users/evansj/events{/privacy}","received_events_url":"https://api.github.com/users/evansj/received_events","type":"User","site_admin":false},"labels":[],"state":"closed","locked":false,"assignee":null,"assignees":[],"milestone":null,"comments":0,"created_at":"2018-11-05T12:05:38Z","updated_at":"2018-11-09T06:12:11Z","closed_at":"2018-11-09T06:12:11Z","author_association":"CONTRIBUTOR","body":"Apologies if this is the wrong place to report this. I'm using OpenHab 2.3.0.\r\n\r\nThe [reschedule() method of the org.eclipse.smarthome.model.script.actions.Timer interface](https://github.com/eclipse/smarthome/blob/master/bundles/model/org.eclipse.smarthome.model.script/src/org/eclipse/smarthome/model/script/actions/Timer.java#L48) has the following comments:\r\n\r\n```java\r\n    /**\r\n     * Reschedules a timer to a new starting time.\r\n     * This can also be called after a timer has terminated, which will result in another\r\n     * execution of the same code.\r\n     * \r\n     * @param newTime the new time to execute the code\r\n     * @return true, if the rescheduling was done successful\r\n     */\r\n    public boolean reschedule(AbstractInstant newTime);\r\n```\r\n\r\nNote, it explicitly states that `reschedule(AbstractInstant)` can be called after the timer has terminated. In practice this is true, but the rescheduled timer never fires.\r\n\r\nI created a test based on a random item I already had defined, `ManualMode`, which I updated the state of using the OpenHAB API while monitoring the logs.\r\n\r\n```java\r\nvar Timer testTimer\r\nval t = 5 // how many seconds to run the timer for\r\n\r\nrule \"Timer testing\"\r\nwhen\r\n  Item ManualMode received update\r\nthen\r\n  logDebug(\"rule\", \"Timer Test: ManualMode state is now {}\", ManualMode.state)\r\n  if (testTimer === null) {\r\n    val firingTime = now.plusSeconds(t);\r\n    testTimer = createTimer(firingTime) [\r\n      logDebug(\"rule\", \"testTimer firing at {}: testTimer.isRunning(): {} testTimer.hasTerminated(): {}\", now, testTimer.isRunning(), testTimer.hasTerminated())\r\n    ]\r\n    logDebug(\"rule\", \"Timer Test: testTimer ({}) created, will fire at {}\", testTimer.class.name, firingTime)\r\n  } else {\r\n    logDebug(\"rule\", \"testTimer.isRunning(): {} testTimer.hasTerminated(): {}\", testTimer.isRunning(), testTimer.hasTerminated())\r\n    val rescheduleTime = now.plusSeconds(t);\r\n    val rescheduled = testTimer.reschedule(rescheduleTime)\r\n    logDebug(\"rule\", \"Timer Test: rescheduled to {}: {}\", rescheduleTime, rescheduled)\r\n    logDebug(\"rule\", \"testTimer.isRunning(): {} testTimer.hasTerminated(): {}\", testTimer.isRunning(), testTimer.hasTerminated())\r\n  }\r\nend\r\n```\r\n\r\nHere is the result of me refreshing the rules file, then updating the ManualMode item state to ON, waiting for the timer to fire, then updating the ManualMode item state to ON again:\r\n\r\n```\r\n2018-11-05 11:50:07.386 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'timer.rules'\r\n2018-11-05 11:50:08.500 [INFO ] [el.core.internal.ModelRepositoryImpl] - Refreshing model 'timer.rules'\r\n2018-11-05 11:50:12.495 [DEBUG] [.eclipse.smarthome.model.script.rule] - Timer Test: ManualMode state is now ON\r\n2018-11-05 11:50:12.496 [DEBUG] [.eclipse.smarthome.model.script.rule] - Timer Test: testTimer (org.eclipse.smarthome.model.script.internal.actions.TimerImpl) created, will fire at 2018-11-05T11:50:17.495Z\r\n2018-11-05 11:50:17.496 [DEBUG] [.eclipse.smarthome.model.script.rule] - testTimer firing at 2018-11-05T11:50:17.495Z: testTimer.isRunning(): true testTimer.hasTerminated(): false\r\n2018-11-05 11:50:20.732 [DEBUG] [.eclipse.smarthome.model.script.rule] - Timer Test: ManualMode state is now ON\r\n2018-11-05 11:50:20.733 [DEBUG] [.eclipse.smarthome.model.script.rule] - testTimer.isRunning(): false testTimer.hasTerminated(): true\r\n2018-11-05 11:50:20.734 [DEBUG] [.eclipse.smarthome.model.script.rule] - Timer Test: rescheduled to 2018-11-05T11:50:25.733Z: true\r\n2018-11-05 11:50:20.734 [DEBUG] [.eclipse.smarthome.model.script.rule] - testTimer.isRunning(): false testTimer.hasTerminated(): false\r\n```\r\n\r\nYou can see from the log that the timer gets created successfully the first time the rule fires, and the timer also fires 5 seconds later. You can also see that the `isRunning()` state is correct (it's `true` while the timer code is executing - this caught me out at first because I incorrectly assumed it would be `true` while the timer was \"ticking\" and `false` when it had expired).\r\n\r\nWhen I update the item state again, the `reschedule(AbstractInstant)` method is called, and it returns `true` which should mean that it was rescheduled successfully. The `hasTerminated()` flag gets reset to `false`. However, the rescheduled timer never actually fires (the next message in the log after the one above was from a few minutes later from something unrelated).\r\n\r\nI can successfully reschedule the timer *before* it terminates. Here is a log of that test, where I update the item state three times before letting it fire, then try to reschedule it again:\r\n\r\n```\r\n2018-11-05 12:01:18.803 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'timer.rules'\r\n2018-11-05 12:01:20.311 [INFO ] [el.core.internal.ModelRepositoryImpl] - Refreshing model 'timer.rules'\r\n2018-11-05 12:01:26.141 [DEBUG] [.eclipse.smarthome.model.script.rule] - Timer Test: ManualMode state is now ON\r\n2018-11-05 12:01:26.143 [DEBUG] [.eclipse.smarthome.model.script.rule] - Timer Test: testTimer (org.eclipse.smarthome.model.script.internal.actions.TimerImpl) created, will fire at 2018-11-05T12:01:31.142Z\r\n2018-11-05 12:01:27.145 [DEBUG] [.eclipse.smarthome.model.script.rule] - Timer Test: ManualMode state is now ON\r\n2018-11-05 12:01:27.146 [DEBUG] [.eclipse.smarthome.model.script.rule] - testTimer.isRunning(): false testTimer.hasTerminated(): false\r\n2018-11-05 12:01:27.147 [DEBUG] [.eclipse.smarthome.model.script.rule] - Timer Test: rescheduled to 2018-11-05T12:01:32.146Z: true\r\n2018-11-05 12:01:27.147 [DEBUG] [.eclipse.smarthome.model.script.rule] - testTimer.isRunning(): false testTimer.hasTerminated(): false\r\n2018-11-05 12:01:28.022 [DEBUG] [.eclipse.smarthome.model.script.rule] - Timer Test: ManualMode state is now ON\r\n2018-11-05 12:01:28.023 [DEBUG] [.eclipse.smarthome.model.script.rule] - testTimer.isRunning(): false testTimer.hasTerminated(): false\r\n2018-11-05 12:01:28.024 [DEBUG] [.eclipse.smarthome.model.script.rule] - Timer Test: rescheduled to 2018-11-05T12:01:33.024Z: true\r\n2018-11-05 12:01:28.025 [DEBUG] [.eclipse.smarthome.model.script.rule] - testTimer.isRunning(): false testTimer.hasTerminated(): false\r\n2018-11-05 12:01:28.862 [DEBUG] [.eclipse.smarthome.model.script.rule] - Timer Test: ManualMode state is now ON\r\n2018-11-05 12:01:28.863 [DEBUG] [.eclipse.smarthome.model.script.rule] - testTimer.isRunning(): false testTimer.hasTerminated(): false\r\n2018-11-05 12:01:28.864 [DEBUG] [.eclipse.smarthome.model.script.rule] - Timer Test: rescheduled to 2018-11-05T12:01:33.863Z: true\r\n2018-11-05 12:01:28.865 [DEBUG] [.eclipse.smarthome.model.script.rule] - testTimer.isRunning(): false testTimer.hasTerminated(): false\r\n2018-11-05 12:01:33.864 [DEBUG] [.eclipse.smarthome.model.script.rule] - testTimer firing at 2018-11-05T12:01:33.864Z: testTimer.isRunning(): true testTimer.hasTerminated(): false\r\n2018-11-05 12:01:36.944 [DEBUG] [.eclipse.smarthome.model.script.rule] - Timer Test: ManualMode state is now ON\r\n2018-11-05 12:01:36.945 [DEBUG] [.eclipse.smarthome.model.script.rule] - testTimer.isRunning(): false testTimer.hasTerminated(): true\r\n2018-11-05 12:01:36.945 [DEBUG] [.eclipse.smarthome.model.script.rule] - Timer Test: rescheduled to 2018-11-05T12:01:41.945Z: true\r\n2018-11-05 12:01:36.946 [DEBUG] [.eclipse.smarthome.model.script.rule] - testTimer.isRunning(): false testTimer.hasTerminated(): false\r\n```"},"comment":{"url":"https://api.github.com/repos/eclipse/smarthome/issues/comments/437261137","html_url":"https://github.com/eclipse/smarthome/issues/6456#issuecomment-437261137","issue_url":"https://api.github.com/repos/eclipse/smarthome/issues/6456","id":437261137,"node_id":"MDEyOklzc3VlQ29tbWVudDQzNzI2MTEzNw==","user":{"login":"kaikreuzer","id":3244965,"node_id":"MDQ6VXNlcjMyNDQ5NjU=","avatar_url":"https://avatars3.githubusercontent.com/u/3244965?v=4","gravatar_id":"","url":"https://api.github.com/users/kaikreuzer","html_url":"https://github.com/kaikreuzer","followers_url":"https://api.github.com/users/kaikreuzer/followers","following_url":"https://api.github.com/users/kaikreuzer/following{/other_user}","gists_url":"https://api.github.com/users/kaikreuzer/gists{/gist_id}","starred_url":"https://api.github.com/users/kaikreuzer/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/kaikreuzer/subscriptions","organizations_url":"https://api.github.com/users/kaikreuzer/orgs","repos_url":"https://api.github.com/users/kaikreuzer/repos","events_url":"https://api.github.com/users/kaikreuzer/events{/privacy}","received_events_url":"https://api.github.com/users/kaikreuzer/received_events","type":"User","site_admin":false},"created_at":"2018-11-09T06:12:11Z","updated_at":"2018-11-09T06:12:11Z","author_association":"MEMBER","body":"Fixed by #6480."}}
{"actor":{"display_login":"kaikreuzer"}}