Skip to content
New issue

Have a question about this project? # for a free GitHub account to open an issue and contact its maintainers and the community.

#

By clicking “#”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? # to your account

Jump to bottom

Rake Task only runs the first time #51

Closed
travisdock opened this issue Mar 11, 2023 · 4 comments · Fixed by #52
Closed

Rake Task only runs the first time #51

travisdock opened this issue Mar 11, 2023 · 4 comments · Fixed by #52

Comments

@travisdock
Copy link

I am trying to use arask to run a simple recurring rake task and it runs the first time but silently fails after that.

I have reproduced the issue in my repo in a branch called arask-test
https://github.com/travisdock/sum/tree/arask-test

The test branch contains a task (lib/tasks/test.rake) that runs every minute. In the output below you can see that it runs the first time (Even though the arask output says 0 runs there is a 'puts' method that you can see prints "You did it"), but after that first run it never prints again even though arask jobs are enqueued and performed.

If you would like to run the project to see for yourself it is fully dockerized and you should be able to run it with just docker compose up

sum-web-1       | * Listening on http://0.0.0.0:3000
sum-web-1       | Use Ctrl-C to stop
sum-web-1       | [ActiveJob] [Arask::RunJobs] [c2db8cfb-4714-4a57-b916-9986e3764ffc] Performing Arask::RunJobs (Job ID: c2db8cfb-4714-4a57-b916-9986e3764ffc) from Async(default) enqueued at 2023-03-11T14:11:06Z
sum-web-1       | [ActiveJob] [Arask::RunJobs] [c2db8cfb-4714-4a57-b916-9986e3764ffc]   TRANSACTION (0.2ms)  BEGIN
sum-web-1       | [ActiveJob] [Arask::RunJobs] [c2db8cfb-4714-4a57-b916-9986e3764ffc]   Arask::AraskJob Load (0.7ms)  SELECT "arask_jobs".* FROM "arask_jobs" WHERE (execute_at < '2023-03-11 14:12:00.130862') FOR UPDATE
sum-web-1       | [ActiveJob] [Arask::RunJobs] [c2db8cfb-4714-4a57-b916-9986e3764ffc]   Arask::AraskJob Update (0.5ms)  UPDATE "arask_jobs" SET "execute_at" = $1, "updated_at" = $2 WHERE "arask_jobs"."id" = $3  [["execute_at", "2023-03-11 14:13:00"], ["updated_at", "2023-03-11 14:12:00.138032"], ["id", 4]]
sum-web-1       | Run options: --seed 30915
sum-web-1       | 
sum-web-1       | # Running:
sum-web-1       | 
sum-web-1       | 
sum-web-1       | 
sum-web-1       | Finished in 0.000800s, 0.0000 runs/s, 0.0000 assertions/s.
sum-web-1       | 0 runs, 0 assertions, 0 failures, 0 errors, 0 skips
sum-web-1       | You did it
sum-web-1       | [ActiveJob] [Arask::RunJobs] [c2db8cfb-4714-4a57-b916-9986e3764ffc] Running daily recurring entries
sum-web-1       | [ActiveJob] [Arask::RunJobs] [c2db8cfb-4714-4a57-b916-9986e3764ffc]   TRANSACTION (0.8ms)  COMMIT
sum-web-1       | [ActiveJob] [Arask::RunJobs] [c2db8cfb-4714-4a57-b916-9986e3764ffc]   Arask::AraskJob Load (0.3ms)  SELECT "arask_jobs".* FROM "arask_jobs" ORDER BY "arask_jobs"."execute_at" ASC LIMIT $1  [["LIMIT", 1]]
sum-web-1       | [ActiveJob] [Arask::RunJobs] [c2db8cfb-4714-4a57-b916-9986e3764ffc] Enqueued Arask::RunJobs (Job ID: 179c6e14-f902-4af5-84bf-11d9ccce0055) to Async(default) at 2023-03-11 14:13:00 UTC
sum-web-1       | [ActiveJob] [Arask::RunJobs] [c2db8cfb-4714-4a57-b916-9986e3764ffc] Performed Arask::RunJobs (Job ID: c2db8cfb-4714-4a57-b916-9986e3764ffc) from Async(default) in 4143.04ms
sum-web-1       | [ActiveJob] [Arask::RunJobs] [179c6e14-f902-4af5-84bf-11d9ccce0055] Performing Arask::RunJobs (Job ID: 179c6e14-f902-4af5-84bf-11d9ccce0055) from Async(default) enqueued at 2023-03-11T14:12:04Z
sum-web-1       | [ActiveJob] [Arask::RunJobs] [179c6e14-f902-4af5-84bf-11d9ccce0055]   TRANSACTION (0.2ms)  BEGIN
sum-web-1       | [ActiveJob] [Arask::RunJobs] [179c6e14-f902-4af5-84bf-11d9ccce0055]   Arask::AraskJob Load (0.4ms)  SELECT "arask_jobs".* FROM "arask_jobs" WHERE (execute_at < '2023-03-11 14:13:00.088752') FOR UPDATE
sum-web-1       | [ActiveJob] [Arask::RunJobs] [179c6e14-f902-4af5-84bf-11d9ccce0055]   Arask::AraskJob Update (0.4ms)  UPDATE "arask_jobs" SET "execute_at" = $1, "updated_at" = $2 WHERE "arask_jobs"."id" = $3  [["execute_at", "2023-03-11 14:14:00"], ["updated_at", "2023-03-11 14:13:00.094966"], ["id", 4]]
sum-web-1       | [ActiveJob] [Arask::RunJobs] [179c6e14-f902-4af5-84bf-11d9ccce0055]   TRANSACTION (1.1ms)  COMMIT
sum-web-1       | [ActiveJob] [Arask::RunJobs] [179c6e14-f902-4af5-84bf-11d9ccce0055]   Arask::AraskJob Load (0.3ms)  SELECT "arask_jobs".* FROM "arask_jobs" ORDER BY "arask_jobs"."execute_at" ASC LIMIT $1  [["LIMIT", 1]]
sum-web-1       | [ActiveJob] [Arask::RunJobs] [179c6e14-f902-4af5-84bf-11d9ccce0055] Enqueued Arask::RunJobs (Job ID: d7377188-436b-410c-b24e-5b243e53fa7c) to Async(default) at 2023-03-11 14:14:00 UTC
sum-web-1       | [ActiveJob] [Arask::RunJobs] [179c6e14-f902-4af5-84bf-11d9ccce0055] Performed Arask::RunJobs (Job ID: 179c6e14-f902-4af5-84bf-11d9ccce0055) from Async(default) in 963.99ms at 2023-03-11 14:15:00 UTC
@Ebbe
Copy link
Owner

Ebbe commented Mar 13, 2023

That is indeed an error. I'll make an update soon. Thank you for the test environment 👍

Ebbe added a commit that referenced this issue Mar 13, 2023
@Ebbe
Try to fix tasks only running once. #51
eaca52b
@Ebbe Ebbe mentioned this issue Mar 13, 2023
Merged
@Ebbe
Copy link
Owner

Ebbe commented Mar 27, 2023

@travisdock Could you be able to test my pr (#52)? Just update the gem files directly and restart the rails server.

@travisdock
Copy link
Author

@Ebbe I updated my Gemfile to use the branch
gem 'arask', git: "https://github.com/Ebbe/arask.git", branch: "fix_tasks_only_run_once"
And it appears to be working! The test task runs every minute as expected.

@travisdock
Copy link
Author

travisdock commented Mar 27, 2023 •
edited
Loading 

sum-web-1       | [ActiveJob] [Arask::RunJobs] [1ae3456c-105d-4691-8158-9a90089a94dc] Running daily recurring entries                                                                                                              
sum-web-1       | [ActiveJob] [Arask::RunJobs] [1ae3456c-105d-4691-8158-9a90089a94dc]   TRANSACTION (1.0ms)  COMMIT                                                                                                                
sum-web-1       | [ActiveJob] [Arask::RunJobs] [1ae3456c-105d-4691-8158-9a90089a94dc]   Arask::AraskJob Load (0.3ms)  SELECT "arask_jobs".* FROM "arask_jobs" ORDER BY "arask_jobs"."execute_at" ASC LIMIT $1  [["LIMIT", 1]]              
sum-web-1       | [ActiveJob] [Arask::RunJobs] [1ae3456c-105d-4691-8158-9a90089a94dc] Enqueued Arask::RunJobs (Job ID: 3f9e947e-b247-416e-ac43-3ecf30563d5b) to Async(default) at 2023-03-27 13:15:00 UTC                                  
sum-web-1       | [ActiveJob] [Arask::RunJobs] [1ae3456c-105d-4691-8158-9a90089a94dc] Performed Arask::RunJobs (Job ID: 1ae3456c-105d-4691-8158-9a90089a94dc) from Async(default) in 22.18ms                                               
sum-postgres-1  | 2023-03-27 13:14:08.723 UTC [26] LOG:  checkpoint complete: wrote 98 buffers (0.6%); 0 WAL file(s) added, 0 removed, 0 recycled; write=9.677 s, sync=0.011 s, total=9.696 s; sync files=59, longest=0.004 s, average=0.001
 s; distance=395 kB, estimate=395 kB                                                                                                                                                                        
sum-web-1       | [ActiveJob] [Arask::RunJobs] [3f9e947e-b247-416e-ac43-3ecf30563d5b] Performing Arask::RunJobs (Job ID: 3f9e947e-b247-416e-ac43-3ecf30563d5b) from Async(default) enqueued at 2023-03-27T13:14:00Z                        
sum-web-1       | [ActiveJob] [Arask::RunJobs] [3f9e947e-b247-416e-ac43-3ecf30563d5b]   TRANSACTION (0.2ms)  BEGIN                                                                                                                 
sum-web-1       | [ActiveJob] [Arask::RunJobs] [3f9e947e-b247-416e-ac43-3ecf30563d5b]   Arask::AraskJob Load (0.4ms)  SELECT "arask_jobs".* FROM "arask_jobs" WHERE (execute_at < '2023-03-27 13:15:00.081353') FOR UPDATE                 
sum-web-1       | [ActiveJob] [Arask::RunJobs] [3f9e947e-b247-416e-ac43-3ecf30563d5b]   Arask::AraskJob Update (0.4ms)  UPDATE "arask_jobs" SET "execute_at" = $1, "updated_at" = $2 WHERE "arask_jobs"."id" = $3  [["execute_at", "2023-03-
27 13:16:00"], ["updated_at", "2023-03-27 13:15:00.088434"], ["id", 5]]                                                                                                                                     
sum-web-1       | You did it                                                                                                                                                                                        
sum-web-1       | [ActiveJob] [Arask::RunJobs] [3f9e947e-b247-416e-ac43-3ecf30563d5b] Running daily recurring entries
sum-web-1       | [ActiveJob] [Arask::RunJobs] [3f9e947e-b247-416e-ac43-3ecf30563d5b]   TRANSACTION (0.9ms)  COMMIT
sum-web-1       | [ActiveJob] [Arask::RunJobs] [3f9e947e-b247-416e-ac43-3ecf30563d5b]   Arask::AraskJob Load (0.3ms)  SELECT "arask_jobs".* FROM "arask_jobs" ORDER BY "arask_jobs"."execute_at" ASC LIMIT $1  [["LIMIT", 1]]
sum-web-1       | [ActiveJob] [Arask::RunJobs] [3f9e947e-b247-416e-ac43-3ecf30563d5b] Enqueued Arask::RunJobs (Job ID: 67952634-3bb4-4e56-8191-abea87c91bee) to Async(default) at 2023-03-27 13:16:00 UTC
sum-web-1       | [ActiveJob] [Arask::RunJobs] [3f9e947e-b247-416e-ac43-3ecf30563d5b] Performed Arask::RunJobs (Job ID: 3f9e947e-b247-416e-ac43-3ecf30563d5b) from Async(default) in 21.89ms
sum-web-1       | [ActiveJob] [Arask::RunJobs] [67952634-3bb4-4e56-8191-abea87c91bee] Performing Arask::RunJobs (Job ID: 67952634-3bb4-4e56-8191-abea87c91bee) from Async(default) enqueued at 2023-03-27T13:15:00Z
sum-web-1       | [ActiveJob] [Arask::RunJobs] [67952634-3bb4-4e56-8191-abea87c91bee]   TRANSACTION (0.2ms)  BEGIN
sum-web-1       | [ActiveJob] [Arask::RunJobs] [67952634-3bb4-4e56-8191-abea87c91bee]   Arask::AraskJob Load (0.4ms)  SELECT "arask_jobs".* FROM "arask_jobs" WHERE (execute_at < '2023-03-27 13:16:00.052484') FOR UPDATE
sum-web-1       | [ActiveJob] [Arask::RunJobs] [67952634-3bb4-4e56-8191-abea87c91bee]   Arask::AraskJob Update (0.4ms)  UPDATE "arask_jobs" SET "execute_at" = $1, "updated_at" = $2 WHERE "arask_jobs"."id" = $3  [["execute_at", "2023-03-
27 13:17:00"], ["updated_at", "2023-03-27 13:16:00.060221"], ["id", 5]]                                               
sum-web-1       | You did it                               
sum-web-1       | [ActiveJob] [Arask::RunJobs] [67952634-3bb4-4e56-8191-abea87c91bee] Running daily recurring entries
sum-web-1       | [ActiveJob] [Arask::RunJobs] [67952634-3bb4-4e56-8191-abea87c91bee]   TRANSACTION (0.8ms)  COMMIT
sum-web-1       | [ActiveJob] [Arask::RunJobs] [67952634-3bb4-4e56-8191-abea87c91bee]   Arask::AraskJob Load (0.4ms)  SELECT "arask_jobs".* FROM "arask_jobs" ORDER BY "arask_jobs"."execute_at" ASC LIMIT $1  [["LIMIT", 1]]
sum-web-1       | [ActiveJob] [Arask::RunJobs] [67952634-3bb4-4e56-8191-abea87c91bee] Enqueued Arask::RunJobs (Job ID: f8773203-0f98-499b-90dd-d6ba4c327999) to Async(default) at 2023-03-27 13:17:00 UTC
sum-web-1       | [ActiveJob] [Arask::RunJobs] [67952634-3bb4-4e56-8191-abea87c91bee] Performed Arask::RunJobs (Job ID: 67952634-3bb4-4e56-8191-abea87c91bee) from Async(default) in 21.95ms
sum-web-1       | [ActiveJob] [Arask::RunJobs] [f8773203-0f98-499b-90dd-d6ba4c327999] Performing Arask::RunJobs (Job ID: f8773203-0f98-499b-90dd-d6ba4c327999) from Async(default) enqueued at 2023-03-27T13:16:00Z
sum-web-1       | [ActiveJob] [Arask::RunJobs] [f8773203-0f98-499b-90dd-d6ba4c327999]   TRANSACTION (0.2ms)  BEGIN
sum-web-1       | [ActiveJob] [Arask::RunJobs] [f8773203-0f98-499b-90dd-d6ba4c327999]   Arask::AraskJob Load (0.4ms)  SELECT "arask_jobs".* FROM "arask_jobs" WHERE (execute_at < '2023-03-27 13:17:00.048808') FOR UPDATE
sum-web-1       | [ActiveJob] [Arask::RunJobs] [f8773203-0f98-499b-90dd-d6ba4c327999]   Arask::AraskJob Update (0.4ms)  UPDATE "arask_jobs" SET "execute_at" = $1, "updated_at" = $2 WHERE "arask_jobs"."id" = $3  [["execute_at", "2023-03-
27 13:18:00"], ["updated_at", "2023-03-27 13:17:00.054818"], ["id", 5]]                                               
sum-web-1       | You did it

@Ebbe Ebbe closed this as completed in #52 Mar 30, 2023
Ebbe added a commit that referenced this issue Mar 30, 2023
@Ebbe
Merge pull request #52 from Ebbe/fix_tasks_only_run_once
8097880 
Try to fix tasks only running once. #51
# for free to join this conversation on GitHub. Already have an account? # to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

Try to fix tasks only running once. #51 Ebbe/arask
2 participants
@Ebbe @travisdock