You are viewing a plain text version of this content. The canonical link for it is here.

Posted to dev@roller.apache.org by Dave <sn...@gmail.com> on 2007/10/05 06:21:02 UTC

VOTE: release RC7 as Apache Roller 4.0

I believe Roller 4.0 is ready for release. The code base has been in
production at several sites for months now, it's gone through several
rounds of testing at Sun and we've tested and fixed six RCs here on
the dev mailing list.

The release files are here:
   http://people.apache.org/~snoopdave/apache-roller-4.0-rc7/

The only changes since RC6 are:
- Support for encrypted passwords in Admin API
- Removal of Henry Yandel from default blog roll

So please take a final look at the release files, try the 5-minute
install if you haven't already and let's vote this release out the
door.

Thanks,
- Dave

Re: VOTE: release RC7 as Apache Roller 4.0

Posted by Jonathan Chen <da...@gmail.com>.

Hi all,

On 16/10/2007, Jonathan Chen <da...@gmail.com> wrote:
> Hi Dave,
>
> On 16/10/2007, Dave <sn...@gmail.com> wrote:
>
> [...]
> > I'm not having any problem with my reset hits and turn-over referrers
> > tasks. Unfortunately, I don't have much experience with the new task
> > management system. I suppose it is possible that your task-lock table
> > has become inconsistent -- so you might want to try stopping Roller,
> > clearing the roller_tasklock table and then restarting.
>
> I had a closer look at the logs, and the lease aquisition failure
> appears to be happening with *all* the tasks. On clearing the table as
> suggested above, the problem goes away. I did have a look at the data
> before clearing, and again once the system restarted; I suspect that
> the daylight savings changeover (which happened during my upgrade from
> 3.1 to 4.0) may have had something to do with the failure to acquire a
> valid lease.

Well, I had a dig in the code yesterday, and that hypothesis proved to
be incorrect. The problem looks to be either in OpenJPA or the
PostgreSQL driver. There appears to be a loss of precision when
dealing with Dates and database timestamps when building queries.
Timestamps values from roller_tasklock were being read as Dates with
millisecond precision from the database; but queries generated using
those Dates values only had centisecond precision. This resulted in
the rows not being found, and thus not being updated for lease
acquisition.

This problem raises it head with PostgreSQL, as timestamp
database-values are stored to the millisecond. MySQL doesn't store
fractional seconds, and so doesn't have the problem.

For the time being, I worked around the problem by hacking
TaskLock.orm.xml to ignore using roller_tasklock.timeAcquired as a
search criteria when updating a row for lease-acquisition; I'll dig
into the OpenJPA and/or the PostgreSQL driver later.

Cheers.
-- 
Jonathan Chen <da...@gmail.com>

Re: VOTE: release RC7 as Apache Roller 4.0

Posted by Jonathan Chen <da...@gmail.com>.

Hi Dave,

On 16/10/2007, Dave <sn...@gmail.com> wrote:

[...]
> I'm not having any problem with my reset hits and turn-over referrers
> tasks. Unfortunately, I don't have much experience with the new task
> management system. I suppose it is possible that your task-lock table
> has become inconsistent -- so you might want to try stopping Roller,
> clearing the roller_tasklock table and then restarting.

I had a closer look at the logs, and the lease aquisition failure
appears to be happening with *all* the tasks. On clearing the table as
suggested above, the problem goes away. I did have a look at the data
before clearing, and again once the system restarted; I suspect that
the daylight savings changeover (which happened during my upgrade from
3.1 to 4.0) may have had something to do with the failure to acquire a
valid lease.

I'm glad the problem has been worked around, and will probably poke
around in the code to see if I can figure why it got confused.

> Also, how do you have your tasks configured? Are you using the default
> start times and intervals?

Default values only.

> And, do you know if this behavior exists on Tomcat too, or just Geronimo?

Tomcat as well.

Cheers.
-- 
Jonathan Chen <da...@gmail.com>

Re: VOTE: release RC7 as Apache Roller 4.0

Posted by Dave <sn...@gmail.com>.

On 10/15/07, Jonathan Chen <da...@gmail.com> wrote:
> I've attached a log snippet below. It looks like the
> ResetHitsCountTask is Launched, but fails to aquire a lease, and then
> when it retries it decides that it can't run and decides to wait until
> next midnight - but that's only an uninformed view. I hope the logs
> can tell you exactly what's happening here.
>
> Cheers.
> --
> Jonathan Chen <da...@gmail.com>
>
> --- Roller debug log ---
> DEBUG 2007-10-16 00:00:00,050 GeronimoLog:debug - Current time = Tue
> Oct 16 00:00:00 NZDT 2007
> DEBUG 2007-10-16 00:00:00,052 GeronimoLog:debug - Started - Tue Oct 16
> 00:00:00 NZDT 2007
> DEBUG 2007-10-16 00:00:00,055 GeronimoLog:debug -
> ScheduledEntriesTask: next allowed run time = Sat Sep 29 17:11:00 NZST
> 2007
> DEBUG 2007-10-16 00:00:00,056 GeronimoLog:debug - MISSED last run,
> checking if waiting is necessary
> DEBUG 2007-10-16 00:00:00,056 GeronimoLog:debug -
> ScheduledEntriesTask: LAUNCHING task
> DEBUG 2007-10-16 00:00:00,058 GeronimoLog:debug -
> ScheduledEntriesTask: Attempting to acquire lease
> DEBUG 2007-10-16 00:00:00,066 GeronimoLog:debug -
> ScheduledEntriesTask: Lease NOT acquired, cannot continue

I'm not having any problem with my reset hits and turn-over referrers
tasks. Unfortunately, I don't have much experience with the new task
management system. I suppose it is possible that your task-lock table
has become inconsistent -- so you might want to try stopping Roller,
clearing the roller_tasklock table and then restarting.

Also, how do you have your tasks configured? Are you using the default
start times and intervals?

And, do you know if this behavior exists on Tomcat too, or just Geronimo?

- Dave

Re: VOTE: release RC7 as Apache Roller 4.0

Posted by Jonathan Chen <da...@gmail.com>.

Hi Dave,

On 12/10/2007, Dave <sn...@gmail.com> wrote:
> On 10/11/07, Jonathan Chen <da...@gmail.com> wrote:
> > On 12/10/2007, Dave <sn...@gmail.com> wrote:
> > > On 10/10/07, Jonathan Chen <da...@gmail.com> wrote:
> > > > I've been running 4.0 RC7 with PostgreSQL on Geronimo2 for almost a
> > > > week now, and I'm noticing that it doesn't appear to reset the
> > > > "Today's Hits" with the frontpage-theme; nor the count on [Create &
> > > > Edit] -> [Referrers] -> "Hits Counted Today" on a user's login. Is
> > > > anyone else seeing this?
> > >
> > > Could this be a caching issue? Are the values being reset in the
> > > database? What happens if you clear the cache. Do you see any evidence
> > > in the logs that the tasks are running?
> >
> > I had a look in the database, and I noticed that referer.reftime is
> > null for all the rows in the table. Perhaps this could be the cause
> > for the non-expiry?
>
> Hmm... I don't think that would stop the reset. I guess it is more
> likely that the reset is not running or hitting some other error.
>
> Are you seeing the task manager startup like so:
>
> INFO  2007-10-11 17:01:03,115 ThreadManagerImpl:initialize -
> Initializing task: ResetHitCountsTask
> INFO  2007-10-11 17:01:03,181 ThreadManagerImpl:initialize -
> Initializing task: TurnoverReferersTask
> INFO  2007-10-11 17:01:03,197 ThreadManagerImpl:initialize -
> Initializing task: PingQueueTask
> INFO  2007-10-11 17:01:03,228 ThreadManagerImpl:initialize -
> Initializing task: RefreshRollerPlanetTask
> INFO  2007-10-11 17:01:03,260 ThreadManagerImpl:initialize -
> Initializing task: SyncWebsitesTask

Yes.

> For more debug output, turn up debugging on task manager like so:
>     log4j.category.org.apache.roller.weblogger.business.runnable=DEBUG
>
> And watch what happens when tasks start and stop.

I've attached a log snippet below. It looks like the
ResetHitsCountTask is Launched, but fails to aquire a lease, and then
when it retries it decides that it can't run and decides to wait until
next midnight - but that's only an uninformed view. I hope the logs
can tell you exactly what's happening here.

Cheers.
-- 
Jonathan Chen <da...@gmail.com>

--- Roller debug log ---
DEBUG 2007-10-16 00:00:00,050 GeronimoLog:debug - Current time = Tue
Oct 16 00:00:00 NZDT 2007
DEBUG 2007-10-16 00:00:00,052 GeronimoLog:debug - Started - Tue Oct 16
00:00:00 NZDT 2007
DEBUG 2007-10-16 00:00:00,055 GeronimoLog:debug -
ScheduledEntriesTask: next allowed run time = Sat Sep 29 17:11:00 NZST
2007
DEBUG 2007-10-16 00:00:00,056 GeronimoLog:debug - MISSED last run,
checking if waiting is necessary
DEBUG 2007-10-16 00:00:00,056 GeronimoLog:debug -
ScheduledEntriesTask: LAUNCHING task
DEBUG 2007-10-16 00:00:00,058 GeronimoLog:debug -
ScheduledEntriesTask: Attempting to acquire lease
DEBUG 2007-10-16 00:00:00,066 GeronimoLog:debug -
ScheduledEntriesTask: Lease NOT acquired, cannot continue
DEBUG 2007-10-16 00:00:00,068 GeronimoLog:debug - ResetHitCountsTask:
next allowed run time = Sat Sep 29 00:00:00 NZST 2007
DEBUG 2007-10-16 00:00:00,069 GeronimoLog:debug - MISSED last run,
checking if waiting is necessary
DEBUG 2007-10-16 00:00:00,069 GeronimoLog:debug - ResetHitCountsTask:
LAUNCHING task
DEBUG 2007-10-16 00:00:00,072 GeronimoLog:debug -
TurnoverReferersTask: next allowed run time = Sat Sep 29 00:00:00 NZST
2007
DEBUG 2007-10-16 00:00:00,073 GeronimoLog:debug - MISSED last run,
checking if waiting is necessary
DEBUG 2007-10-16 00:00:00,073 GeronimoLog:debug -
TurnoverReferersTask: LAUNCHING task
DEBUG 2007-10-16 00:00:00,077 GeronimoLog:debug - PingQueueTask: next
allowed run time = Sat Sep 29 13:18:56 NZST 2007
DEBUG 2007-10-16 00:00:00,077 GeronimoLog:debug - MISSED last run,
checking if waiting is necessary
DEBUG 2007-10-16 00:00:00,078 GeronimoLog:debug - PingQueueTask: LAUNCHING task
DEBUG 2007-10-16 00:00:00,078 GeronimoLog:debug - Finished
DEBUG 2007-10-16 00:00:00,079 GeronimoLog:debug - sleeping - 59970
DEBUG 2007-10-16 00:00:00,079 GeronimoLog:debug - ResetHitCountsTask:
Attempting to acquire lease
DEBUG 2007-10-16 00:00:00,081 GeronimoLog:debug -
TurnoverReferersTask: Attempting to acquire lease
DEBUG 2007-10-16 00:00:00,089 GeronimoLog:debug - PingQueueTask:
Attempting to acquire lease
DEBUG 2007-10-16 00:00:00,094 GeronimoLog:debug -
TurnoverReferersTask: Lease NOT acquired, cannot continue
DEBUG 2007-10-16 00:00:00,108 GeronimoLog:debug - PingQueueTask: Lease
NOT acquired, cannot continue
DEBUG 2007-10-16 00:00:00,113 GeronimoLog:debug - ResetHitCountsTask:
Lease NOT acquired, cannot continue
DEBUG 2007-10-16 00:00:43,416 GeronimoLog:debug - Completed: 0 secs
DEBUG 2007-10-16 00:00:43,417 GeronimoLog:debug -
HitCountQueueProcessor SLEEPING for 180000 milliseconds ...
DEBUG 2007-10-16 00:01:00,051 GeronimoLog:debug - Current time = Tue
Oct 16 00:01:00 NZDT 2007
DEBUG 2007-10-16 00:01:00,051 GeronimoLog:debug - Started - Tue Oct 16
00:01:00 NZDT 2007
DEBUG 2007-10-16 00:01:00,057 GeronimoLog:debug -
ScheduledEntriesTask: next allowed run time = Sat Sep 29 17:11:00 NZST
2007
DEBUG 2007-10-16 00:01:00,058 GeronimoLog:debug - MISSED last run,
checking if waiting is necessary
DEBUG 2007-10-16 00:01:00,058 GeronimoLog:debug -
ScheduledEntriesTask: LAUNCHING task
DEBUG 2007-10-16 00:01:00,061 GeronimoLog:debug - ResetHitCountsTask:
next allowed run time = Sat Sep 29 00:00:00 NZST 2007
DEBUG 2007-10-16 00:01:00,062 GeronimoLog:debug - MISSED last run,
checking if waiting is necessary
DEBUG 2007-10-16 00:01:00,062 GeronimoLog:debug - ResetHitCountsTask:
LAUNCHING task
DEBUG 2007-10-16 00:01:00,066 GeronimoLog:debug -
TurnoverReferersTask: next allowed run time = Sat Sep 29 00:00:00 NZST
2007
DEBUG 2007-10-16 00:01:00,066 GeronimoLog:debug - MISSED last run,
checking if waiting is necessary
DEBUG 2007-10-16 00:01:00,067 GeronimoLog:debug -
TurnoverReferersTask: LAUNCHING task
DEBUG 2007-10-16 00:01:00,070 GeronimoLog:debug - PingQueueTask: next
allowed run time = Sat Sep 29 13:18:56 NZST 2007
DEBUG 2007-10-16 00:01:00,071 GeronimoLog:debug - MISSED last run,
checking if waiting is necessary
DEBUG 2007-10-16 00:01:00,071 GeronimoLog:debug - PingQueueTask: LAUNCHING task
DEBUG 2007-10-16 00:01:00,072 GeronimoLog:debug - Finished
DEBUG 2007-10-16 00:01:00,073 GeronimoLog:debug - sleeping - 59976
DEBUG 2007-10-16 00:01:00,071 GeronimoLog:debug -
TurnoverReferersTask: Attempting to acquire lease
DEBUG 2007-10-16 00:01:00,080 GeronimoLog:debug - PingQueueTask:
Attempting to acquire lease
DEBUG 2007-10-16 00:01:00,071 GeronimoLog:debug - ResetHitCountsTask:
Attempting to acquire lease
DEBUG 2007-10-16 00:01:00,094 GeronimoLog:debug - ResetHitCountsTask:
Lease NOT acquired, cannot continue
DEBUG 2007-10-16 00:01:00,096 GeronimoLog:debug -
TurnoverReferersTask: Lease NOT acquired, cannot continue
DEBUG 2007-10-16 00:01:00,071 GeronimoLog:debug -
ScheduledEntriesTask: Attempting to acquire lease
DEBUG 2007-10-16 00:01:00,104 GeronimoLog:debug -
ScheduledEntriesTask: Lease NOT acquired, cannot continue
DEBUG 2007-10-16 00:01:00,106 GeronimoLog:debug - PingQueueTask: Lease
NOT acquired, cannot continue
DEBUG 2007-10-16 00:02:00,051 GeronimoLog:debug - Current time = Tue
Oct 16 00:02:00 NZDT 2007
DEBUG 2007-10-16 00:02:00,051 GeronimoLog:debug - Started - Tue Oct 16
00:02:00 NZDT 2007
DEBUG 2007-10-16 00:02:00,055 GeronimoLog:debug -
ScheduledEntriesTask: next allowed run time = Sat Sep 29 17:11:00 NZST
2007
DEBUG 2007-10-16 00:02:00,056 GeronimoLog:debug - MISSED last run,
checking if waiting is necessary
DEBUG 2007-10-16 00:02:00,056 GeronimoLog:debug -
ScheduledEntriesTask: LAUNCHING task
DEBUG 2007-10-16 00:02:00,059 GeronimoLog:debug - ResetHitCountsTask:
next allowed run time = Sat Sep 29 00:00:00 NZST 2007
DEBUG 2007-10-16 00:02:00,060 GeronimoLog:debug - MISSED last run,
checking if waiting is necessary
DEBUG 2007-10-16 00:02:00,060 GeronimoLog:debug - WAITING for next
reasonable run time

Re: VOTE: release RC7 as Apache Roller 4.0

Posted by Jonathan Chen <da...@gmail.com>.

On 12/10/2007, Dave <sn...@gmail.com> wrote:

[..]
> For more debug output, turn up debugging on task manager like so:
>     log4j.category.org.apache.roller.weblogger.business.runnable=DEBUG
>
> And watch what happens when tasks start and stop.

I've managed to locate the roller logs, and it's reporting:

ERROR 2007-10-12 14:38:27,622 GeronimoLog:error - Problem in doStop of
org.apache.roller/roller/4.0/war?J2EEApplication=null,PersistenceUnitModule=WEB-INF/lib/roller-business.jar,WebModule=org.apache.roller/roller/4.0/war,j2eeType=PersistenceUnit,name=RollerPU
<0.9.7-incubating fatal user error>
org.apache.openjpa.persistence.ArgumentException: A JDBC Driver or
DataSource class name must be specified in the ConnectionDriverName
property.
	at org.apache.openjpa.jdbc.schema.DataSourceFactory.newDataSource(DataSourceFactory.java:70)
	at org.apache.openjpa.jdbc.conf.JDBCConfigurationImpl.createConnectionFactory(JDBCConfigurationImpl.java:800)
	at org.apache.openjpa.jdbc.conf.JDBCConfigurationImpl.getDBDictionaryInstance(JDBCConfigurationImpl.java:566)
	at org.apache.openjpa.jdbc.meta.MappingRepository.endConfiguration(MappingRepository.java:1185)
	at org.apache.openjpa.lib.conf.Configurations.configureInstance(Configurations.java:450)
	at org.apache.openjpa.lib.conf.Configurations.configureInstance(Configurations.java:375)
	at org.apache.openjpa.lib.conf.PluginValue.instantiate(PluginValue.java:102)
	at org.apache.openjpa.lib.conf.ObjectValue.instantiate(ObjectValue.java:79)
	at org.apache.openjpa.conf.OpenJPAConfigurationImpl.newMetaDataRepositoryInstance(OpenJPAConfigurationImpl.java:831)
	at org.apache.openjpa.conf.OpenJPAConfigurationImpl.getMetaDataRepositoryInstance(OpenJPAConfigurationImpl.java:826)
[...]

It looks like some seems to be some configuration confusion between
Roller's OpenJPA and Geronimo's OpenJPA usage. I'm not sure why the
scheduled tasks can't seem to find the same Datasource name that the
main roller app uses.

Any suggestions welcome. I'll have a look at the code as well.

Cheers.
-- 
Jonathan Chen <da...@gmail.com>

Re: VOTE: release RC7 as Apache Roller 4.0

Posted by Dave <sn...@gmail.com>.

On 10/11/07, Jonathan Chen <da...@gmail.com> wrote:
> On 12/10/2007, Dave <sn...@gmail.com> wrote:
> > On 10/10/07, Jonathan Chen <da...@gmail.com> wrote:
> > > I've been running 4.0 RC7 with PostgreSQL on Geronimo2 for almost a
> > > week now, and I'm noticing that it doesn't appear to reset the
> > > "Today's Hits" with the frontpage-theme; nor the count on [Create &
> > > Edit] -> [Referrers] -> "Hits Counted Today" on a user's login. Is
> > > anyone else seeing this?
> >
> > Could this be a caching issue? Are the values being reset in the
> > database? What happens if you clear the cache. Do you see any evidence
> > in the logs that the tasks are running?
>
> I had a look in the database, and I noticed that referer.reftime is
> null for all the rows in the table. Perhaps this could be the cause
> for the non-expiry?

Hmm... I don't think that would stop the reset. I guess it is more
likely that the reset is not running or hitting some other error.

Are you seeing the task manager startup like so:

INFO  2007-10-11 17:01:03,115 ThreadManagerImpl:initialize -
Initializing task: ResetHitCountsTask
INFO  2007-10-11 17:01:03,181 ThreadManagerImpl:initialize -
Initializing task: TurnoverReferersTask
INFO  2007-10-11 17:01:03,197 ThreadManagerImpl:initialize -
Initializing task: PingQueueTask
INFO  2007-10-11 17:01:03,228 ThreadManagerImpl:initialize -
Initializing task: RefreshRollerPlanetTask
INFO  2007-10-11 17:01:03,260 ThreadManagerImpl:initialize -
Initializing task: SyncWebsitesTask

For more debug output, turn up debugging on task manager like so:
    log4j.category.org.apache.roller.weblogger.business.runnable=DEBUG

And watch what happens when tasks start and stop.

- Dave

Re: VOTE: release RC7 as Apache Roller 4.0

Posted by Jonathan Chen <da...@gmail.com>.

On 12/10/2007, Dave <sn...@gmail.com> wrote:
> On 10/10/07, Jonathan Chen <da...@gmail.com> wrote:
> > I've been running 4.0 RC7 with PostgreSQL on Geronimo2 for almost a
> > week now, and I'm noticing that it doesn't appear to reset the
> > "Today's Hits" with the frontpage-theme; nor the count on [Create &
> > Edit] -> [Referrers] -> "Hits Counted Today" on a user's login. Is
> > anyone else seeing this?
>
> Could this be a caching issue? Are the values being reset in the
> database? What happens if you clear the cache. Do you see any evidence
> in the logs that the tasks are running?

I had a look in the database, and I noticed that referer.reftime is
null for all the rows in the table. Perhaps this could be the cause
for the non-expiry?

Cheers.
-- 
Jonathan Chen <da...@gmail.com>

Re: VOTE: release RC7 as Apache Roller 4.0

Posted by Dave <sn...@gmail.com>.

On 10/10/07, Jonathan Chen <da...@gmail.com> wrote:
> I've been running 4.0 RC7 with PostgreSQL on Geronimo2 for almost a
> week now, and I'm noticing that it doesn't appear to reset the
> "Today's Hits" with the frontpage-theme; nor the count on [Create &
> Edit] -> [Referrers] -> "Hits Counted Today" on a user's login. Is
> anyone else seeing this?

Could this be a caching issue? Are the values being reset in the
database? What happens if you clear the cache. Do you see any evidence
in the logs that the tasks are running?

- Dave

Re: VOTE: release RC7 as Apache Roller 4.0

Posted by Jonathan Chen <da...@gmail.com>.

Hi,

I've been running 4.0 RC7 with PostgreSQL on Geronimo2 for almost a
week now, and I'm noticing that it doesn't appear to reset the
"Today's Hits" with the frontpage-theme; nor the count on [Create &
Edit] -> [Referrers] -> "Hits Counted Today" on a user's login. Is
anyone else seeing this?

Cheers.
-- 
Jonathan Chen <da...@gmail.com>