ciao-scheduler still checks the deleted job
Closed this issue · 2 comments
Describe the bug
ciao-scheduler still checks status of destroyed job
To Reproduce
Steps to reproduce the behavior:
1. Create job to listen to a fake website https://www.brotandgames.com/ciaos/, ciao sent notification of status change to '404'
I, [2019-08-30T17:48:42.059041 #1] INFO -- : [aa51d8d0-17e6-489c-afe4-bfd555d37a7b] ciao-scheduler Created job 'cron_1567187322.0564888_47382620780640' D, [2019-08-30T17:48:42.060153 #1] DEBUG -- : [aa51d8d0-17e6-489c-afe4-bfd555d37a7b] Check Update (0.2ms) UPDATE "checks" SET "job" = ?, "next_contact_at" = ? WHERE "checks"."id" = ? [["job", "cron_1567187322.0564888_47382620780640"], ["next_contact_at", "2019-08-30 17:49:00"], ["id", 1]] D, [2019-08-30T17:48:42.074029 #1] DEBUG -- : [aa51d8d0-17e6-489c-afe4-bfd555d37a7b] (13.7ms) commit transaction I, [2019-08-30T17:48:42.074750 #1] INFO -- : [aa51d8d0-17e6-489c-afe4-bfd555d37a7b] Redirected to http://localhost:8090/checks/1 I, [2019-08-30T17:48:42.074931 #1] INFO -- : [aa51d8d0-17e6-489c-afe4-bfd555d37a7b] Completed 302 Found in 26ms (ActiveRecord: 15.0ms | Allocations: 3810) I, [2019-08-30T17:48:42.078510 #1] INFO -- : [1ebd7531-2894-4b19-8228-f5e4dd0e4ed4] Started GET "/checks/1" for 172.19.0.1 at 2019-08-30 17:48:42 +0000 I, [2019-08-30T17:48:42.079181 #1] INFO -- : [1ebd7531-2894-4b19-8228-f5e4dd0e4ed4] Processing by ChecksController#show as HTML I, [2019-08-30T17:48:42.079248 #1] INFO -- : [1ebd7531-2894-4b19-8228-f5e4dd0e4ed4] Parameters: {"id"=>"1"} D, [2019-08-30T17:48:42.080663 #1] DEBUG -- : [1ebd7531-2894-4b19-8228-f5e4dd0e4ed4] Check Load (0.2ms) SELECT "checks".* FROM "checks" WHERE "checks"."id" = ? LIMIT ? [["id", 1], ["LIMIT", 1]] I, [2019-08-30T17:48:42.081500 #1] INFO -- : [1ebd7531-2894-4b19-8228-f5e4dd0e4ed4] Rendering checks/show.html.erb within layouts/application I, [2019-08-30T17:48:42.083150 #1] INFO -- : [1ebd7531-2894-4b19-8228-f5e4dd0e4ed4] Rendered checks/show.html.erb within layouts/application (Duration: 1.6ms | Allocations: 737) I, [2019-08-30T17:48:42.083956 #1] INFO -- : [1ebd7531-2894-4b19-8228-f5e4dd0e4ed4] Completed 200 OK in 5ms (Views: 2.6ms | ActiveRecord: 0.2ms | Allocations: 2035) I, [2019-08-30T17:48:43.790431 #1] INFO -- : [4621b832-7e9b-40c8-a708-4a7f95f22bdf] Started GET "/checks" for 172.19.0.1 at 2019-08-30 17:48:43 +0000 I, [2019-08-30T17:48:43.793506 #1] INFO -- : [4621b832-7e9b-40c8-a708-4a7f95f22bdf] Processing by ChecksController#index as HTML I, [2019-08-30T17:48:43.800384 #1] INFO -- : [4621b832-7e9b-40c8-a708-4a7f95f22bdf] Rendering checks/index.html.erb within layouts/application D, [2019-08-30T17:48:43.811135 #1] DEBUG -- : [4621b832-7e9b-40c8-a708-4a7f95f22bdf] Check Load (1.1ms) SELECT "checks".* FROM "checks" I, [2019-08-30T17:48:43.815240 #1] INFO -- : [4621b832-7e9b-40c8-a708-4a7f95f22bdf] Rendered checks/index.html.erb within layouts/application (Duration: 14.5ms | Allocations: 1078) I, [2019-08-30T17:48:43.820324 #1] INFO -- : [4621b832-7e9b-40c8-a708-4a7f95f22bdf] Completed 200 OK in 25ms (Views: 19.1ms | ActiveRecord: 1.1ms | Allocations: 2049) I, [2019-08-30T17:49:06.002335 #1] INFO -- : ciao-scheduler Checked 'https://www.brotandgames.com/ciaos/' at '2019-08-31 00:49:06 +0700' and got '404' D, [2019-08-30T17:49:06.021063 #1] DEBUG -- : Check Update (17.1ms) UPDATE "checks" SET "status" = ?, "last_contact_at" = ?, "next_contact_at" = ? WHERE "checks"."id" = ? [["status", "404"], ["last_contact_at", "2019-08-30 17:49:06.002080"], ["next_contact_at", "2019-08-30 17:50:00"], ["id", 1]] I, [2019-08-30T17:49:06.021264 #1] INFO -- : ciao-scheduler Check 'ciao': Status changed from '' to '404'
2. Delete the job
I, [2019-08-30T17:49:26.031284 #1] INFO -- : [af213b8c-6cc6-40c3-8fe6-da53e2d22185] Started DELETE "/checks/1" for 172.19.0.1 at 2019-08-30 17:49:26 +0000 I, [2019-08-30T17:49:26.034254 #1] INFO -- : [af213b8c-6cc6-40c3-8fe6-da53e2d22185] Processing by ChecksController#destroy as HTML I, [2019-08-30T17:49:26.034523 #1] INFO -- : [af213b8c-6cc6-40c3-8fe6-da53e2d22185] Parameters: {"authenticity_token"=>"sdQSsoIKtOud7EGrr4r8CrikbGyqflEb5pEJQajIcKQydTpTFouvG0JUtzTHK1m8/zwK+WElOAiZjFbmz4jZ8A==", "id"=>"1"} D, [2019-08-30T17:49:26.039458 #1] DEBUG -- : [af213b8c-6cc6-40c3-8fe6-da53e2d22185] Check Load (0.6ms) SELECT "checks".* FROM "checks" WHERE "checks"."id" = ? LIMIT ? [["id", 1], ["LIMIT", 1]] D, [2019-08-30T17:49:26.042323 #1] DEBUG -- : [af213b8c-6cc6-40c3-8fe6-da53e2d22185] (0.2ms) begin transaction D, [2019-08-30T17:49:26.043908 #1] DEBUG -- : [af213b8c-6cc6-40c3-8fe6-da53e2d22185] Check Destroy (0.8ms) DELETE FROM "checks" WHERE "checks"."id" = ? [["id", 1]] D, [2019-08-30T17:49:26.063461 #1] DEBUG -- : [af213b8c-6cc6-40c3-8fe6-da53e2d22185] (18.2ms) commit transaction I, [2019-08-30T17:49:26.065355 #1] INFO -- : [af213b8c-6cc6-40c3-8fe6-da53e2d22185] Redirected to http://localhost:8090/checks I, [2019-08-30T17:49:26.065914 #1] INFO -- : [af213b8c-6cc6-40c3-8fe6-da53e2d22185] Completed 302 Found in 31ms (ActiveRecord: 19.9ms | Allocations: 741) I, [2019-08-30T17:49:26.080387 #1] INFO -- : [0d69b06d-9aa5-4373-bc56-da166a5df0d2] Started GET "/checks" for 172.19.0.1 at 2019-08-30 17:49:26 +0000 I, [2019-08-30T17:49:26.083450 #1] INFO -- : [0d69b06d-9aa5-4373-bc56-da166a5df0d2] Processing by ChecksController#index as HTML I, [2019-08-30T17:49:26.088332 #1] INFO -- : [0d69b06d-9aa5-4373-bc56-da166a5df0d2] Rendering checks/index.html.erb within layouts/application D, [2019-08-30T17:49:26.091333 #1] DEBUG -- : [0d69b06d-9aa5-4373-bc56-da166a5df0d2] Check Load (0.5ms) SELECT "checks".* FROM "checks" I, [2019-08-30T17:49:26.091917 #1] INFO -- : [0d69b06d-9aa5-4373-bc56-da166a5df0d2] Rendered checks/index.html.erb within layouts/application (Duration: 3.2ms | Allocations: 191) I, [2019-08-30T17:49:26.093838 #1] INFO -- : [0d69b06d-9aa5-4373-bc56-da166a5df0d2] Completed 200 OK in 10ms (Views: 6.3ms | ActiveRecord: 0.5ms | Allocations: 1023)
3. Check logs and see that job was being checked
I, [2019-08-30T17:49:26.031284 #1] INFO -- : [af213b8c-6cc6-40c3-8fe6-da53e2d22185] Started DELETE "/checks/1" for 172.19.0.1 at 2019-08-30 17:49:26 +0000 I, [2019-08-30T17:49:26.034254 #1] INFO -- : [af213b8c-6cc6-40c3-8fe6-da53e2d22185] Processing by ChecksController#destroy as HTML I, [2019-08-30T17:49:26.034523 #1] INFO -- : [af213b8c-6cc6-40c3-8fe6-da53e2d22185] Parameters: {"authenticity_token"=>"sdQSsoIKtOud7EGrr4r8CrikbGyqflEb5pEJQajIcKQydTpTFouvG0JUtzTHK1m8/zwK+WElOAiZjFbmz4jZ8A==", "id"=>"1"} D, [2019-08-30T17:49:26.039458 #1] DEBUG -- : [af213b8c-6cc6-40c3-8fe6-da53e2d22185] Check Load (0.6ms) SELECT "checks".* FROM "checks" WHERE "checks"."id" = ? LIMIT ? [["id", 1], ["LIMIT", 1]] D, [2019-08-30T17:49:26.042323 #1] DEBUG -- : [af213b8c-6cc6-40c3-8fe6-da53e2d22185] (0.2ms) begin transaction D, [2019-08-30T17:49:26.043908 #1] DEBUG -- : [af213b8c-6cc6-40c3-8fe6-da53e2d22185] Check Destroy (0.8ms) DELETE FROM "checks" WHERE "checks"."id" = ? [["id", 1]] D, [2019-08-30T17:49:26.063461 #1] DEBUG -- : [af213b8c-6cc6-40c3-8fe6-da53e2d22185] (18.2ms) commit transaction I, [2019-08-30T17:49:26.065355 #1] INFO -- : [af213b8c-6cc6-40c3-8fe6-da53e2d22185] Redirected to http://localhost:8090/checks I, [2019-08-30T17:49:26.065914 #1] INFO -- : [af213b8c-6cc6-40c3-8fe6-da53e2d22185] Completed 302 Found in 31ms (ActiveRecord: 19.9ms | Allocations: 741) I, [2019-08-30T17:49:26.080387 #1] INFO -- : [0d69b06d-9aa5-4373-bc56-da166a5df0d2] Started GET "/checks" for 172.19.0.1 at 2019-08-30 17:49:26 +0000 I, [2019-08-30T17:49:26.083450 #1] INFO -- : [0d69b06d-9aa5-4373-bc56-da166a5df0d2] Processing by ChecksController#index as HTML I, [2019-08-30T17:49:26.088332 #1] INFO -- : [0d69b06d-9aa5-4373-bc56-da166a5df0d2] Rendering checks/index.html.erb within layouts/application D, [2019-08-30T17:49:26.091333 #1] DEBUG -- : [0d69b06d-9aa5-4373-bc56-da166a5df0d2] Check Load (0.5ms) SELECT "checks".* FROM "checks" I, [2019-08-30T17:49:26.091917 #1] INFO -- : [0d69b06d-9aa5-4373-bc56-da166a5df0d2] Rendered checks/index.html.erb within layouts/application (Duration: 3.2ms | Allocations: 191) I, [2019-08-30T17:49:26.093838 #1] INFO -- : [0d69b06d-9aa5-4373-bc56-da166a5df0d2] Completed 200 OK in 10ms (Views: 6.3ms | ActiveRecord: 0.5ms | Allocations: 1023) **I, [2019-08-30T17:50:01.367594 #1] INFO -- : ciao-scheduler Checked 'https://www.brotandgames.com/ciaos/' at '2019-08-31 00:50:01 +0700' and got '404' D, [2019-08-30T17:50:01.368662 #1] DEBUG -- : Check Update (0.2ms) UPDATE "checks" SET "status" = ?, "last_contact_at" = ?, "next_contact_at" = ? WHERE "checks"."id" = ? [["status", "404"], ["last_contact_at", "2019-08-30 17:50:01.367424"], ["next_contact_at", "2019-08-30 17:51:00"], ["id", 1]] I, [2019-08-30T17:51:07.340141 #1] INFO -- : ciao-scheduler Checked 'https://www.brotandgames.com/ciaos/' at '2019-08-31 00:51:07 +0700' and got '404' D, [2019-08-30T17:51:07.342188 #1] DEBUG -- : Check Update (0.4ms) UPDATE "checks" SET "status" = ?, "last_contact_at" = ?, "next_contact_at" = ? WHERE "checks"."id" = ? [["status", "404"], ["last_contact_at", "2019-08-30 17:51:07.339910"], ["next_contact_at", "2019-08-30 17:52:00"], ["id", 1]]**
Expected behavior
Job should be deleted completely from cron-job
@Finneon Thanks for reporting.
WIll be fixed in the next release.