Hi Dave,
Have dumped a lot of logs etc in this email.
Nick
Dave wrote:
On Jan 7, 2008 7:04 PM, Nick Hortovanyi <[EMAIL PROTECTED]> 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
