roller-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Dave <snoopd...@gmail.com>
Subject Re: Task Scheduler not running ResetHitCountsTask and other tasks
Date Wed, 23 Jan 2008 04:16:31 GMT
I'm not sure what is going on here and I don't have time to
investigate right now so I filed a bug:

   http://opensource.atlassian.com/projects/roller/browse/ROL-1657

Hopefully somebody will revisit before our next release.

- Dave



On Jan 12, 2008 4:28 AM, Nick Hortovanyi <nick@toasttechnology.com.au> wrote:
> Hi Dave,
>
> Have dumped a lot of logs etc in this email.
>
> Nick
>
> Dave wrote:
> > On Jan 7, 2008 7:04 PM, Nick Hortovanyi <nick@toasttechnology.com.au> wrote:
> >
> >> TaskScheduler does not appear to work with Apache Roller 4 and
> >> Postgres.. any ideas?
> >>
> >> DEBUG 2008-01-08 00:00:00,058 TaskScheduler:run - Current time = Tue Jan
> >> 08 00:00:00 CST 2008
> >> DEBUG 2008-01-08 00:00:00,059 TaskScheduler:runTasks - Started - Tue Jan
> >> 08 00:00:00 CST 2008
> >> DEBUG 2008-01-08 00:00:00,060 TaskScheduler:runTasks -
> >>
> >
> > Question: In the logs, is there any evidence that tasks ever ran?
> >
> This was an upgrade from Roller 3.1. Did get the tasks to run once.
> Believe I removed the entries from roller_tasklock.
>
> > I'm not sure what is causing these problems with the scheduler. I have
> > not encountered them on my Roller systems, which run MySQL.
> >
> > One theory is that the task lock table is getting corrupted. I believe
> > some folks have been able to work around the problem by removing all
> > data from the 'roller_tasklocks' table. If you try that please let us
> > know if it works on not.
> >
> Here is the current data in the table
> roller=> select * from roller_tasklock
> roller-> \g
>                   id                  |          name           |
> islocked |           timeacquired           | timeleased |
> lastrun          |     client
> --------------------------------------+-------------------------+----------+----------------------------------+------------+---------------------------+-----------------
>  b6a3a294-f474-4264-b188-cc4c03708545 | SyncWebsitesTask        |
> f        | 1970-01-01 09:30:00+09:30        |          0 | 1970-01-01
> 09:30:00+09:30 |
>  3e2efcbb-e059-47b1-9ee8-29d7a5c2ca2e | RefreshRollerPlanetTask |
> f        | 1970-01-01 09:30:00+09:30        |          0 | 1970-01-01
> 09:30:00+09:30 |
>  079b4415-1287-43c1-b720-60f24433153d | ScheduledEntriesTask    |
> f        | 2007-12-24 10:08:00.134127+10:30 |         30 | 2007-12-24
> 10:08:00+10:30 | defaultClientId
>  7762e849-cdb1-4c0e-ac76-75ee92668653 | PingQueueTask           |
> f        | 2007-12-24 10:08:00.149668+10:30 |         30 | 2007-12-24
> 10:08:00+10:30 | defaultClientId
>  485648c0-358c-42b2-8fc4-62c27740e3fa | ResetHitCountsTask      |
> f        | 2007-12-25 00:00:00.061304+10:30 |         30 | 2007-12-25
> 00:00:00+10:30 | defaultClientId
>  f37c99ef-8fff-4cad-b7dd-9f64a6ed76dc | TurnoverReferersTask    |
> f        | 2007-12-25 00:00:00.066401+10:30 |         30 | 2007-12-25
> 00:00:00+10:30 | defaultClientId
> (6 rows)
>
> roller=>
>
> The log follows after I remove the entries before restarting tomcat
> DEBUG 2008-01-12 19:44:00,057 TaskScheduler:run - Current time = Sat Jan
> 12 19:44:00 CST 2008
> DEBUG 2008-01-12 19:44:00,057 TaskScheduler:runTasks - Started - Sat Jan
> 12 19:44:00 CST 2008
> WARN  2008-01-12 19:44:00,060 TaskScheduler:runTasks -
> ScheduledEntriesTask: Unhandled exception caught
> java.lang.NullPointerException
>         at
> org.apache.roller.weblogger.business.runnable.TaskScheduler.runTasks(TaskScheduler.java:142)
>         at
> org.apache.roller.weblogger.business.runnable.TaskScheduler.run(TaskScheduler.java:90)
>         at java.lang.Thread.run(Thread.java:810)
> WARN  2008-01-12 19:44:00,070 TaskScheduler:runTasks -
> ResetHitCountsTask: Unhandled exception caught
> java.lang.NullPointerException
>         at
> org.apache.roller.weblogger.business.runnable.TaskScheduler.runTasks(TaskScheduler.java:142)
>         at
> org.apache.roller.weblogger.business.runnable.TaskScheduler.run(TaskScheduler.java:90)
>         at java.lang.Thread.run(Thread.java:810)
> WARN  2008-01-12 19:44:00,087 TaskScheduler:runTasks -
> TurnoverReferersTask: Unhandled exception caught
> java.lang.NullPointerException
>         at
> org.apache.roller.weblogger.business.runnable.TaskScheduler.runTasks(TaskScheduler.java:142)
>         at
> org.apache.roller.weblogger.business.runnable.TaskScheduler.run(TaskScheduler.java:90)
>         at java.lang.Thread.run(Thread.java:810)
> WARN  2008-01-12 19:44:02,123 TaskScheduler:runTasks - PingQueueTask:
> Unhandled exception caught
> java.lang.NullPointerException
>         at
> org.apache.roller.weblogger.business.runnable.TaskScheduler.runTasks(TaskScheduler.java:142)
>         at
> org.apache.roller.weblogger.business.runnable.TaskScheduler.run(TaskScheduler.java:90)
>         at java.lang.Thread.run(Thread.java:810)
> WARN  2008-01-12 19:44:02,125 TaskScheduler:runTasks - SyncWebsitesTask:
> Unhandled exception caught
> java.lang.NullPointerException
>         at
> org.apache.roller.weblogger.business.runnable.TaskScheduler.runTasks(TaskScheduler.java:142)
>         at
> org.apache.roller.weblogger.business.runnable.TaskScheduler.run(TaskScheduler.java:90)
>         at java.lang.Thread.run(Thread.java:810)
> WARN  2008-01-12 19:44:02,126 TaskScheduler:runTasks -
> RefreshRollerPlanetTask: Unhandled exception caught
> java.lang.NullPointerException
>         at
> org.apache.roller.weblogger.business.runnable.TaskScheduler.runTasks(TaskScheduler.java:142)
>         at
> org.apache.roller.weblogger.business.runnable.TaskScheduler.run(TaskScheduler.java:90)
>         at java.lang.Thread.run(Thread.java:810)
> DEBUG 2008-01-12 19:44:02,126 TaskScheduler:runTasks - Finished
> DEBUG 2008-01-12 19:44:02,127 TaskScheduler:run - sleeping - 57922
>
> Restarted tomcat
> INFO  2008-01-12 19:47:14,435 ThreadManagerImpl:initialize -
> Initializing task: ScheduledEntriesTask
> DEBUG 2008-01-12 19:47:14,452 ThreadManagerImpl:initialize - Task record
> does not exist, inserting empty record to start with
> INFO  2008-01-12 19:47:14,454 ThreadManagerImpl:initialize -
> Initializing task: ResetHitCountsTask
> DEBUG 2008-01-12 19:47:14,456 ThreadManagerImpl:initialize - Task record
> does not exist, inserting empty record to start with
> INFO  2008-01-12 19:47:14,457 ThreadManagerImpl:initialize -
> Initializing task: TurnoverReferersTask
> DEBUG 2008-01-12 19:47:14,459 ThreadManagerImpl:initialize - Task record
> does not exist, inserting empty record to start with
> INFO  2008-01-12 19:47:14,459 ThreadManagerImpl:initialize -
> Initializing task: PingQueueTask
> DEBUG 2008-01-12 19:47:14,470 ThreadManagerImpl:initialize - Task record
> does not exist, inserting empty record to start with
> INFO  2008-01-12 19:47:14,471 ThreadManagerImpl:initialize -
> Initializing task: SyncWebsitesTask
> DEBUG 2008-01-12 19:47:14,492 ThreadManagerImpl:initialize - Task record
> does not exist, inserting empty record to start with
> INFO  2008-01-12 19:47:14,493 ThreadManagerImpl:initialize -
> Initializing task: RefreshRollerPlanetTask
> DEBUG 2008-01-12 19:47:14,496 ThreadManagerImpl:initialize - Task record
> does not exist, inserting empty record to start with
> DEBUG 2008-01-12 19:47:14,497 ThreadManagerImpl:initialize - Starting
> scheduler thread
> DEBUG 2008-01-12 19:47:14,498 TaskScheduler:run - Current time = Sat Jan
> 12 19:47:14 CST 2008
> DEBUG 2008-01-12 19:47:14,499 TaskScheduler:run - Start time = Sat Jan
> 12 19:48:00 CST 2008
> DEBUG 2008-01-12 19:47:14,501 TaskScheduler:run - sleeping - 105548
> ...
> table shows
> roller=> select * from roller_tasklock\g
>                   id                  |          name           |
> islocked |       timeacquired        | timeleased |
> lastrun          | client
> --------------------------------------+-------------------------+----------+---------------------------+------------+---------------------------+--------
>  49646f7d-a967-49c0-a33c-1d01b52f6f4b | ScheduledEntriesTask    |
> f        | 1970-01-01 09:30:00+09:30 |          0 | 1970-01-01
> 09:30:00+09:30 |
>  e736a3a9-37e1-41d3-a373-0b9ce7aca583 | ResetHitCountsTask      |
> f        | 1970-01-01 09:30:00+09:30 |          0 | 1970-01-01
> 09:30:00+09:30 |
>  5de5be9a-67c4-4ac9-ba21-1ef082b2f306 | TurnoverReferersTask    |
> f        | 1970-01-01 09:30:00+09:30 |          0 | 1970-01-01
> 09:30:00+09:30 |
>  98d4e609-2a69-4a13-a7b3-39944ac990df | PingQueueTask           |
> f        | 1970-01-01 09:30:00+09:30 |          0 | 1970-01-01
> 09:30:00+09:30 |
>  76f54a14-56b8-49d1-aeb6-159b7047f65a | SyncWebsitesTask        |
> f        | 1970-01-01 09:30:00+09:30 |          0 | 1970-01-01
> 09:30:00+09:30 |
>  2b1e1826-f43f-435d-9295-645800421398 | RefreshRollerPlanetTask |
> f        | 1970-01-01 09:30:00+09:30 |          0 | 1970-01-01
> 09:30:00+09:30 |
> (6 rows)
>
> roller=>
> ...
> next run
> ...
> DEBUG 2008-01-12 19:49:00,055 TaskScheduler:run - Current time = Sat Jan
> 12 19:49:00 CST 2008
> DEBUG 2008-01-12 19:49:00,055 TaskScheduler:runTasks - Started - Sat Jan
> 12 19:49:00 CST 2008
> DEBUG 2008-01-12 19:49:00,058 TaskScheduler:runTasks -
> ScheduledEntriesTask: next allowed run time = Thu Jan 01 09:31:00 CST 1970
> DEBUG 2008-01-12 19:49:00,058 TaskScheduler:runTasks - MISSED last run,
> checking if waiting is necessary
> DEBUG 2008-01-12 19:49:00,058 TaskScheduler:runTasks -
> ScheduledEntriesTask: LAUNCHING task
> DEBUG 2008-01-12 19:49:00,063 RollerTaskWithLeasing:run -
> ScheduledEntriesTask: Attempting to acquire lease
> DEBUG 2008-01-12 19:49:00,064 TaskScheduler:runTasks -
> ResetHitCountsTask: next allowed run time = Fri Jan 02 09:30:00 CST 1970
> DEBUG 2008-01-12 19:49:00,064 TaskScheduler:runTasks - MISSED last run,
> checking if waiting is necessary
> DEBUG 2008-01-12 19:49:00,065 TaskScheduler:runTasks - WAITING for next
> reasonable run time
> DEBUG 2008-01-12 19:49:00,067 TaskScheduler:runTasks -
> TurnoverReferersTask: next allowed run time = Fri Jan 02 09:30:00 CST 1970
> DEBUG 2008-01-12 19:49:00,067 TaskScheduler:runTasks - MISSED last run,
> checking if waiting is necessary
> DEBUG 2008-01-12 19:49:00,068 TaskScheduler:runTasks - WAITING for next
> reasonable run time
> DEBUG 2008-01-12 19:49:00,070 TaskScheduler:runTasks - PingQueueTask:
> next allowed run time = Thu Jan 01 09:35:00 CST 1970
> DEBUG 2008-01-12 19:49:00,070 TaskScheduler:runTasks - MISSED last run,
> checking if waiting is necessary
> DEBUG 2008-01-12 19:49:00,071 TaskScheduler:runTasks - PingQueueTask:
> LAUNCHING task
> DEBUG 2008-01-12 19:49:00,074 TaskScheduler:runTasks - SyncWebsitesTask:
> next allowed run time = Fri Jan 02 09:30:00 CST 1970
> DEBUG 2008-01-12 19:49:00,074 TaskScheduler:runTasks - MISSED last run,
> checking if waiting is necessary
> DEBUG 2008-01-12 19:49:00,075 TaskScheduler:runTasks - WAITING for next
> reasonable run time
> DEBUG 2008-01-12 19:49:00,076 TaskScheduler:runTasks -
> RefreshRollerPlanetTask: next allowed run time = Thu Jan 01 10:30:00 CST
> 1970
> DEBUG 2008-01-12 19:49:00,076 TaskScheduler:runTasks - MISSED last run,
> checking if waiting is necessary
> DEBUG 2008-01-12 19:49:00,077 TaskScheduler:runTasks - WAITING for next
> reasonable run time
> DEBUG 2008-01-12 19:49:00,077 TaskScheduler:runTasks - Finished
> DEBUG 2008-01-12 19:49:00,078 TaskScheduler:run - sleeping - 59971
> DEBUG 2008-01-12 19:49:00,078 RollerTaskWithLeasing:run - PingQueueTask:
> Attempting to acquire lease
> DEBUG 2008-01-12 19:49:00,084 RollerTaskWithLeasing:run -
> ScheduledEntriesTask: Lease acquired, running task
> DEBUG 2008-01-12 19:49:00,084 ScheduledEntriesTask:runTask - task started
> DEBUG 2008-01-12 19:49:00,085 ScheduledEntriesTask:runTask - looking up
> scheduled entries older than Sat Jan 12 19:49:00 CST 2008
> DEBUG 2008-01-12 19:49:00,103 ScheduledEntriesTask:runTask - promoting 0
> entries to PUBLISHED state
> DEBUG 2008-01-12 19:49:00,114 ScheduledEntriesTask:runTask - task completed
> DEBUG 2008-01-12 19:49:00,114 RollerTaskWithLeasing:run -
> ScheduledEntriesTask: Attempting to release lease
> DEBUG 2008-01-12 19:49:00,120 RollerTaskWithLeasing:run -
> ScheduledEntriesTask: Lease released, task finished
> DEBUG 2008-01-12 19:50:00,051 TaskScheduler:run - Current time = Sat Jan
> 12 19:50:00 CST 2008
> DEBUG 2008-01-12 19:50:00,051 TaskScheduler:runTasks - Started - Sat Jan
> 12 19:50:00 CST 2008
> DEBUG 2008-01-12 19:50:00,054 TaskScheduler:runTasks -
> ScheduledEntriesTask: next allowed run time = Sat Jan 12 19:50:00 CST 2008
> DEBUG 2008-01-12 19:50:00,054 TaskScheduler:runTasks -
> ScheduledEntriesTask: LAUNCHING task
> DEBUG 2008-01-12 19:50:00,054 RollerTaskWithLeasing:run -
> ScheduledEntriesTask: Attempting to acquire lease
> DEBUG 2008-01-12 19:50:00,056 TaskScheduler:runTasks -
> ResetHitCountsTask: next allowed run time = Fri Jan 02 09:30:00 CST 1970
> DEBUG 2008-01-12 19:50:00,056 TaskScheduler:runTasks - MISSED last run,
> checking if waiting is necessary
> DEBUG 2008-01-12 19:50:00,056 TaskScheduler:runTasks - WAITING for next
> reasonable run time
> DEBUG 2008-01-12 19:50:00,058 TaskScheduler:runTasks -
> TurnoverReferersTask: next allowed run time = Fri Jan 02 09:30:00 CST 1970
> DEBUG 2008-01-12 19:50:00,058 TaskScheduler:runTasks - MISSED last run,
> checking if waiting is necessary
> DEBUG 2008-01-12 19:50:00,058 TaskScheduler:runTasks - WAITING for next
> reasonable run time
> DEBUG 2008-01-12 19:50:00,060 TaskScheduler:runTasks - PingQueueTask:
> next allowed run time = Thu Jan 01 09:35:00 CST 1970
> DEBUG 2008-01-12 19:50:00,060 TaskScheduler:runTasks - MISSED last run,
> checking if waiting is necessary
> DEBUG 2008-01-12 19:50:00,060 TaskScheduler:runTasks - PingQueueTask:
> LAUNCHING task
> DEBUG 2008-01-12 19:50:00,061 RollerTaskWithLeasing:run - PingQueueTask:
> Attempting to acquire lease
> DEBUG 2008-01-12 19:50:00,063 TaskScheduler:runTasks - SyncWebsitesTask:
> next allowed run time = Fri Jan 02 09:30:00 CST 1970
> DEBUG 2008-01-12 19:50:00,063 TaskScheduler:runTasks - MISSED last run,
> checking if waiting is necessary
> DEBUG 2008-01-12 19:50:00,063 TaskScheduler:runTasks - WAITING for next
> reasonable run time
> DEBUG 2008-01-12 19:50:00,065 TaskScheduler:runTasks -
> RefreshRollerPlanetTask: next allowed run time = Thu Jan 01 10:30:00 CST
> 1970
> DEBUG 2008-01-12 19:50:00,065 TaskScheduler:runTasks - MISSED last run,
> checking if waiting is necessary
> DEBUG 2008-01-12 19:50:00,065 TaskScheduler:runTasks - WAITING for next
> reasonable run time
> DEBUG 2008-01-12 19:50:00,066 TaskScheduler:runTasks - Finished
> DEBUG 2008-01-12 19:50:00,066 TaskScheduler:run - sleeping - 59983
> DEBUG 2008-01-12 19:50:00,067 RollerTaskWithLeasing:run -
> ScheduledEntriesTask: Lease NOT acquired, cannot continue
> DEBUG 2008-01-12 19:50:00,084 RollerTaskWithLeasing:run - PingQueueTask:
> Lease acquired, running task
>
> >  - Dave
> >
> >
> >
> >
>

Mime
View raw message