Opened 14 years ago
Last modified 10 months ago
#8561 new defect
TracCron doesn't kill processes
Reported by: | Owned by: | ||
---|---|---|---|
Priority: | normal | Component: | TracCronPlugin |
Severity: | major | Keywords: | |
Cc: | Trac Release: | 0.12 |
Description
Have the TracCron running every 5 minutes, but it doesn't appear to kill the processes once the cron process runs, so an additional process is launching every 5 minutes and they're all trying to perform the action.
Attachments (3)
Change History (26)
comment:1 Changed 14 years ago by
Owner: | changed from Thierry Bressure to anonymous |
---|---|
Status: | new → assigned |
comment:2 Changed 14 years ago by
Owner: | changed from anonymous to Thierry Bressure |
---|---|
Status: | assigned → new |
comment:3 Changed 14 years ago by
Status: | new → assigned |
---|
Replying to adam@terrerouge.ca:
Have the TracCron running every 5 minutes, but it doesn't appear to kill the processes once the cron process runs, so an additional process is launching every 5 minutes and they're all trying to perform the action.
I've look up at the code on core.py at line 257. As you can see the Ticker never spawn a new timer if it has not finished with all task (line 267). Then it compute and adjuste the delay to match the schedule.
What is the schedule you are using ? What sort of task are you doing ? if the task spawn a new thread, then TracCronPlugin is not aware of that fact, so it believe (line 264) that all task is finished. ARe you in this case ?
comment:4 Changed 14 years ago by
I'm using the hourly schedule, with the values as "0, 5, 10, 15, 20, 25, 30, 35, 40, 45, 50, 55". The task checks an external system for records matching a certain criteria using a web services API, then inserts/updates the Trac DB with certain values.
I'm not using the thread modules, no.
comment:5 Changed 14 years ago by
@adam : do you think the task take more than 5 minutes to complete ?
If so, the Ticket.wake_up() method will take more than 5 minutes to return from self.callback() and, only after returning from the task execution, the Ticker will respawn a new Timer for next wake_up (not exactely next schedule). Even in this case i don't see how a task can execute while another is processing
How do you think the task is currently executed while another one is processing ? Do you have any error warning you that a concurrent access is done ?
I'm trying to understand how the bug you've reported can happend. Nevertheless, TracCronPlugin do not kill any existing task execution and this may be an enhancement i will done if current TracConPlugin can lead to overlapping task execution.
Thank's for your quick reply.
comment:6 Changed 14 years ago by
The task takes about a minute, maybe less. I don't have any error notifying me of concurrent access. Would running the callback at the end of my process help? At the moment I'm just relying on EOF to break the task called. I didn't notice any callback in the example, so wasn't sure.
The reason I think the task is executing multiple times is because the value of a specific custom field, which is appended with a new value when the task runs successfully, appends multiple times. I can allow for this in my code, but the multiple tasks running is still a significant resource strain.
comment:7 Changed 14 years ago by
@adam: for a running exemple you can take a look at task.py and there is no need to call callback and i will say you must not do so. You just have to implement wake_up() method
To know if the task is executing multiple time you can use administration panel under the Trac Cron entry on the left panel. There are 2 views. In Listener view (sub-entry) be sure you 've checked history_task_event. In History view you will see all task execution Trac Cron Plugin have done. Let'me know what you see.
What do you mean by EOF to break the called task. Do you kill the python process running Trac or your task is actually openning a shell to do is job ?
comment:8 Changed 14 years ago by
The Listener history_task_event is active, but no tasks are recorded.
I neither end the python process nor use a shell command. My db executions happen through the trac.db module and through the api module for the system i'm connecting to - by EOF I just meant that the end of the wake_up function.
comment:9 Changed 14 years ago by
@adam: thank you for this information.
If the history listener is empty that means either the history listener is bugy either the task you run never end.
Can you try the HeartBeatTask ? I've specially done heat for testing purpose: go to admministration page, then under Plugins, then under the group traccron.task you can activate HeartBeatTask.
Check if the listener record each theart beat execution.
If so that means that your task never end because the history listener record only complete execution (add the information only when the task has finished)
Let me kown the result Best regard.
comment:10 Changed 14 years ago by
Thanks - actually, I checked the history again and it is now showing my task as completed successfully, and it completes in the same minute it is called. It was showing one for every 5 minutes from 8h00 Eastern to 9 15 Eastern. I then refreshed the history page and all entries are gone (I did not press "Clear")
comment:11 Changed 14 years ago by
@adam: very good, the history show us that you task is running quite good and take less than 1 minute to complete. Be awaere that the history is only in-memory so every time you restart Trac or every time Trac reload its environment (trac.ini modification, or python file modification in dev mode), the history is lost.
With information you gave me I can say that your task is not concurrently run (for a given Trac instance).
Be sure you've only activate one schedule for your task (ex: hourly scheduler)
Are you sure there is only one Trac instance is accessing the "specific custom field" you mentionned ? Nobody around you are using the same database ?
For the moment killing the task do not make any sens because there is no concurrent task execution.
The purpose of TracCronPlugin is to run a task at the specified schedule you tell him. If you use hourly schedule with 0,5,10,15,...,55 you wan to run the task every five minute and that is it actually does. Do you agree ?
I wait for your feedback before putting this issue as invalid.
Best regard.
comment:12 Changed 14 years ago by
There is only one trac instance running, and nothing else is accessing the database.
The trac.log is showing the same logs from trac[core] at the same point in time, and the number of repeated instances of the trac[core] logs for an execution is the same as the number of times the data gets repeated in the database - this would definitely indicate concurrent tasks running, when none have been requested. Attached is an example of the traccron plugin, in a minute where no activity is required, so one would expect a single check, but instead i see 5 instances of it.
Changed 14 years ago by
Attachment: | traccronlog.txt added |
---|
comment:13 Changed 14 years ago by
@adam: thank you for the log. It definitly show that you had more than one Timer running.
Unfortunatly i don't know how this state have been raised the 15th february. Can you reproduce it now ?
Which version of TracCronPlugin are you using ? Can you tell me what is your version of python . What is you OS (where the bug occured) ?
I'am waiting for those informations.
Regards
comment:14 Changed 14 years ago by
I can reproduce it now, I just don't have a copy of the logs at the moment, can pass those along in an hour or two.
using r9398 (0.3), os is Linux. Python is 2.6
comment:15 Changed 14 years ago by
@adam: i need to determinate if this is an plateform specific issue (regarding thread management) or a task issue or a special case i did not see in TracCronPlugin (e.g a bug in TracCronPlugin)
Please can you enable the HearBeatTask and tell me if you still have multiple instance of the heartBeatTask ?
I dare reproducing this bug.
Best regard.
comment:17 Changed 14 years ago by
attached new log from 11:25 eastern today to 11:41 eastern today, is showing 2 instances of the scheduled tasks per minute instead of one.
Changed 14 years ago by
Attachment: | traclogwithheartbeat.txt added |
---|
comment:18 Changed 14 years ago by
@adam: i've looked at the attachment log. HearBeatTask is checked twice so the issue is not task specific.
The Ticker is currently running more than on Timer object at the same time. It is like there are more than on instance of Core object. This is not reproducible on any environment i've got acces to:
- Windows, python2.7
- Linux, Python 2.6.6
I will made another release of TracCronPlugin with more debug trace of instanciation. You'll find this version next Monday.
comment:19 Changed 14 years ago by
@tbressure - Checked for change yesterday, release still seems to be the same. Should I download from another location?
comment:21 Changed 12 years ago by
Hi, any news about this bug? I'm have created a mail reminder job and mails are sent mutiple times.
Thanks
comment:22 Changed 12 years ago by
Owner: | changed from Thierry Bressure to Tetsuya Morimoto |
---|---|
Status: | assigned → new |
comment:23 Changed 10 months ago by
Owner: | Tetsuya Morimoto deleted |
---|
Yes, this is a real defect. I'll work on it. Thank's for reporting this bug.