I set tasks.RefreshRollerPlanetTask.interval to 5 (minutes) to speed
things up a bit in terms of troubleshooting.
This is what I am seeing in the logs...
1. Created an entry on a blog in my development site:
DEBUG 2008-01-04 15:37:08,094 WebloggerRuntimeConfig:getProperty -
fetched property [site.absoluteurl=http://viking:8080/roller/]
DEBUG 2008-01-04 15:37:08,097 WebloggerRuntimeConfig:getProperty -
fetched property [site.absoluteurl=http://viking:8080/roller/]
DEBUG 2008-01-04 15:37:08,101 WebloggerRuntimeConfig:getProperty -
fetched property [site.absoluteurl=http://viking:8080/roller/]
DEBUG 2008-01-04 15:37:08,135 VelocityRenderer:render - Rendered
[415451e9-dea6-4339-a711-f427a5f43d3b] in 1 secs
DEBUG 2008-01-04 15:37:08,138 CachedContent:flush - FLUSHED 20968
DEBUG 2008-01-04 15:37:08,141 CachedContent:close - CLOSED
DEBUG 2008-01-04 15:37:08,143 PageServlet:doGet - Flushing response output
DEBUG 2008-01-04 15:37:08,147 PageServlet:doGet - PUT
cache.sitewide:page/planet/page=0/user=nkeegan
DEBUG 2008-01-04 15:37:08,149 SiteWideCache:put - PUT
cache.sitewide:page/planet/page=0/user=nkeegan
I see stuff like this:
DEBUG 2008-01-04 15:37:10,522 PersistenceSessionFilter:doFilter -
Releasing Roller Session
DEBUG 2008-01-04 15:37:10,525 WebloggerConfig:getProperty - Fetching
property [planet.aggregator.enabled=true]
DEBUG 2008-01-04 15:37:10,527 PersistenceSessionFilter:doFilter -
Exiting /roller/planet/
DEBUG 2008-01-04 15:37:10,529 BootstrapFilter:doFilter - Exiting
/roller/planet/
DEBUG 2008-01-04 15:37:10,560 CharEncodingFilter:doFilter - Processing
CharEncodingFilter
DEBUG 2008-01-04 15:37:10,561 CharEncodingFilter:doFilter - Set request
character encoding to UTF-8
DEBUG 2008-01-04 15:37:10,563 BootstrapFilter:doFilter - Entered
/roller/images/permalink.gif
DEBUG 2008-01-04 15:37:10,565 PersistenceSessionFilter:doFilter -
Entered /roller/images/permalink.gif
DEBUG 2008-01-04 15:37:10,567 RequestMappingFilter:doFilter - entering
DEBUG 2008-01-04 15:37:10,568 RequestMappingFilter:doFilter - trying
mapper org.apache.roller.weblogger.ui.rendering.WeblogRequestMapper
DEBUG 2008-01-04 15:37:10,570 WeblogRequestMapper:handleRequest -
evaluating [/roller/images/permalink.gif]
DEBUG 2008-01-04 15:37:10,572 WeblogRequestMapper:handleRequest -
potential weblog handle = images
DEBUG 2008-01-04 15:37:10,573 WeblogRequestMapper:handleRequest -
SKIPPED images
DEBUG 2008-01-04 15:37:10,575 RequestMappingFilter:doFilter - request
not mapped
DEBUG 2008-01-04 15:37:10,578 RequestMappingFilter:doFilter - exiting
And then this:
EBUG 2008-01-04 15:37:10,645 WebloggerConfig:getProperty - Fetching
property [planet.aggregator.enabled=true]
DEBUG 2008-01-04 15:37:10,648 PersistenceSessionFilter:doFilter -
Exiting /roller//images/feed-icon-12x12.gif
DEBUG 2008-01-04 15:37:10,649 BootstrapFilter:doFilter - Exiting
/roller//images/feed-icon-12x12.gif
DEBUG 2008-01-04 15:38:00,053 TaskScheduler:run - Current time = Fri Jan
04 15:38:00 MST 2008
DEBUG 2008-01-04 15:38:00,053 TaskScheduler:runTasks - Started - Fri Jan
04 15:38:00 MST 2008
DEBUG 2008-01-04 15:38:00,075 TaskScheduler:runTasks -
ScheduledEntriesTask: next allowed run time = Fri Jan 04 15:13:00 MST 2008
DEBUG 2008-01-04 15:38:00,075 TaskScheduler:runTasks - MISSED last run,
checking if waiting is necessary
DEBUG 2008-01-04 15:38:00,076 TaskScheduler:runTasks -
ScheduledEntriesTask: LAUNCHING task
DEBUG 2008-01-04 15:38:00,076 RollerTaskWithLeasing:run -
ScheduledEntriesTask: Attempting to acquire lease
DEBUG 2008-01-04 15:38:00,077 JPAThreadManagerImpl:registerLease -
Attempting to register lease for task - ScheduledEntriesTask
DEBUG 2008-01-04 15:38:00,096 TaskScheduler:runTasks -
ResetHitCountsTask: next allowed run time = Thu Jan 01 17:00:00 MST 1970
DEBUG 2008-01-04 15:38:00,097 TaskScheduler:runTasks - MISSED last run,
checking if waiting is necessary
DEBUG 2008-01-04 15:38:00,097 TaskScheduler:runTasks - WAITING for next
reasonable run time
DEBUG 2008-01-04 15:38:00,100 JPAThreadManagerImpl:registerLease - last
run = Fri Jan 04 15:12:00 MST 2008
DEBUG 2008-01-04 15:38:00,100 JPAThreadManagerImpl:registerLease - new
run time = Fri Jan 04 15:38:00 MST 2008
DEBUG 2008-01-04 15:38:00,101 JPAThreadManagerImpl:registerLease - last
acquired = Fri Jan 04 15:12:00 MST 2008
DEBUG 2008-01-04 15:38:00,102 JPAThreadManagerImpl:registerLease - time
leased = 30
DEBUG 2008-01-04 15:38:00,102 JPAThreadManagerImpl:registerLease - lease
expiration = Fri Jan 04 15:42:00 MST 2008
DEBUG 2008-01-04 15:38:00,118 TaskScheduler:runTasks -
TurnoverReferersTask: next allowed run time = Thu Jan 01 17:00:00 MST 1970
DEBUG 2008-01-04 15:38:00,119 TaskScheduler:runTasks - MISSED last run,
checking if waiting is necessary
DEBUG 2008-01-04 15:38:00,119 TaskScheduler:runTasks - WAITING for next
reasonable run time
DEBUG 2008-01-04 15:38:00,123 RollerTaskWithLeasing:run -
ScheduledEntriesTask: Lease NOT acquired, cannot continue
DEBUG 2008-01-04 15:38:00,138 TaskScheduler:runTasks - PingQueueTask:
next allowed run time = Fri Jan 04 15:17:00 MST 2008
DEBUG 2008-01-04 15:38:00,139 TaskScheduler:runTasks - MISSED last run,
checking if waiting is necessary
DEBUG 2008-01-04 15:38:00,139 TaskScheduler:runTasks - PingQueueTask:
LAUNCHING task
DEBUG 2008-01-04 15:38:00,140 RollerTaskWithLeasing:run - PingQueueTask:
Attempting to acquire lease
DEBUG 2008-01-04 15:38:00,140 JPAThreadManagerImpl:registerLease -
Attempting to register lease for task - PingQueueTask
DEBUG 2008-01-04 15:38:00,158 TaskScheduler:runTasks -
RefreshRollerPlanetTask: next allowed run time = Wed Dec 31 17:05:00 MST
1969
DEBUG 2008-01-04 15:38:00,158 TaskScheduler:runTasks - MISSED last run,
checking if waiting is necessary
DEBUG 2008-01-04 15:38:00,159 TaskScheduler:runTasks - WAITING for next
reasonable run time
DEBUG 2008-01-04 15:38:00,162 JPAThreadManagerImpl:registerLease - last
run = Fri Jan 04 15:12:00 MST 2008
DEBUG 2008-01-04 15:38:00,168 JPAThreadManagerImpl:registerLease - new
run time = Fri Jan 04 15:38:00 MST 2008
DEBUG 2008-01-04 15:38:00,168 JPAThreadManagerImpl:registerLease - last
acquired = Fri Jan 04 15:12:00 MST 2008
DEBUG 2008-01-04 15:38:00,169 JPAThreadManagerImpl:registerLease - time
leased = 30
DEBUG 2008-01-04 15:38:00,169 JPAThreadManagerImpl:registerLease - lease
expiration = Fri Jan 04 15:42:00 MST 2008
DEBUG 2008-01-04 15:38:00,187 TaskScheduler:runTasks - SyncWebsitesTask:
next allowed run time = Thu Jan 01 17:00:00 MST 1970
DEBUG 2008-01-04 15:38:00,188 TaskScheduler:runTasks - MISSED last run,
checking if waiting is necessary
DEBUG 2008-01-04 15:38:00,188 TaskScheduler:runTasks - WAITING for next
reasonable run time
DEBUG 2008-01-04 15:38:00,189 TaskScheduler:runTasks - Finished
DEBUG 2008-01-04 15:38:00,191 TaskScheduler:run - sleeping - 59858
Not sure what it means.
If I look at the cache directory I can see that the files in that
directory are not being updated in terms of size or time but I'm not
sure if they are supposed to be updated or not.
Assuming the code I posted previously is correct for my front page blog
I'm not sure what I am seeing here in terms of this being normal
behavior or an indication that something is not quite right somewhere.
